[==========] 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:20:14.463119 11242 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.250.190:41709
I20260812 06:20:14.464064 11242 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:20:14.464635 11242 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.470481 11259 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.470506 11255 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:20:14.470628 11242 server_base.cc:1061] running on GCE node
W20260812 06:20:14.470731 11257 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:20:14.471423 11242 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.471529 11242 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:20:14.471570 11242 hybrid_clock.cc:648] HybridClock initialized: now 1786515614471567 us; error 0 us; skew 500 ppm
I20260812 06:20:14.473362 11242 webserver.cc:533] Webserver started at http://127.10.250.190:46401/ using document root <none> and password file <none>
I20260812 06:20:14.474002 11242 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.474076 11242 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.474314 11242 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.475966 11242 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/master-0-root/instance:
uuid: "be33ca98b2e34bea87f07898691fd636"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-tc2s"
I20260812 06:20:14.479277 11242 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:14.481148 11265 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:20:14.482081 11242 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:14.482189 11242 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/master-0-root
uuid: "be33ca98b2e34bea87f07898691fd636"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-tc2s"
I20260812 06:20:14.482270 11242 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-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:20:14.502761 11242 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.503289 11242 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:20:14.503425 11242 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.510318 11242 rpc_server.cc:307] RPC server started. Bound to: 127.10.250.190:41709
I20260812 06:20:14.510324 11355 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.250.190:41709 every 8 connection(s)
I20260812 06:20:14.512436 11357 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:20:14.517505 11357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: Bootstrap starting.
I20260812 06:20:14.519762 11357 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.520603 11357 log.cc:826] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:14.522089 11357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: No bootstrap required, opened a new log
I20260812 06:20:14.524765 11357 raft_consensus.cc:359] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be33ca98b2e34bea87f07898691fd636" member_type: VOTER }
I20260812 06:20:14.524919 11357 raft_consensus.cc:385] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.524993 11357 raft_consensus.cc:740] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: be33ca98b2e34bea87f07898691fd636, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.525544 11357 consensus_queue.cc:260] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [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: "be33ca98b2e34bea87f07898691fd636" member_type: VOTER }
I20260812 06:20:14.525684 11357 raft_consensus.cc:399] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.525748 11357 raft_consensus.cc:493] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.525864 11357 raft_consensus.cc:3060] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.526551 11357 raft_consensus.cc:515] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be33ca98b2e34bea87f07898691fd636" member_type: VOTER }
I20260812 06:20:14.526953 11357 leader_election.cc:304] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [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: be33ca98b2e34bea87f07898691fd636; no voters: 
I20260812 06:20:14.527231 11357 leader_election.cc:290] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.527333 11361 raft_consensus.cc:2804] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.527536 11361 raft_consensus.cc:697] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 1 LEADER]: Becoming Leader. State: Replica: be33ca98b2e34bea87f07898691fd636, State: Running, Role: LEADER
I20260812 06:20:14.527918 11361 consensus_queue.cc:237] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [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: "be33ca98b2e34bea87f07898691fd636" member_type: VOTER }
I20260812 06:20:14.528123 11357 sys_catalog.cc:565] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:14.529637 11363 sys_catalog.cc:455] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [sys.catalog]: SysCatalogTable state changed. Reason: New leader be33ca98b2e34bea87f07898691fd636. Latest consensus state: current_term: 1 leader_uuid: "be33ca98b2e34bea87f07898691fd636" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be33ca98b2e34bea87f07898691fd636" member_type: VOTER } }
I20260812 06:20:14.529670 11362 sys_catalog.cc:455] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "be33ca98b2e34bea87f07898691fd636" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be33ca98b2e34bea87f07898691fd636" member_type: VOTER } }
I20260812 06:20:14.529781 11362 sys_catalog.cc:458] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.529780 11363 sys_catalog.cc:458] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:14.530224 11242 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:14.532066 11382 catalog_manager.cc:1594] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:14.532125 11382 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:14.532191 11379 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:14.532853 11379 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:14.537145 11379 catalog_manager.cc:1383] Generated new cluster ID: 785fa56748ac46258903fb7d0717c6e4
I20260812 06:20:14.537204 11379 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:14.544488 11379 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:14.545224 11379 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:14.552515 11379 catalog_manager.cc:6092] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: Generated new TSK 0
I20260812 06:20:14.552999 11379 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:14.562529 11242 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:14.564821 11388 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:20:14.564891 11390 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:14.564851 11387 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:20:14.565302 11242 server_base.cc:1061] running on GCE node
I20260812 06:20:14.565465 11242 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:14.565500 11242 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:20:14.565514 11242 hybrid_clock.cc:648] HybridClock initialized: now 1786515614565514 us; error 0 us; skew 500 ppm
I20260812 06:20:14.566345 11242 webserver.cc:533] Webserver started at http://127.10.250.129:38495/ using document root <none> and password file <none>
I20260812 06:20:14.566504 11242 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:14.566547 11242 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:14.566617 11242 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:14.566944 11242 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/instance:
uuid: "0f82ea0b1879460a9eac8a1a2cca2c0a"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-tc2s"
I20260812 06:20:14.568276 11242 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:14.569217 11397 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:20:14.569469 11242 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:14.569533 11242 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root
uuid: "0f82ea0b1879460a9eac8a1a2cca2c0a"
format_stamp: "Formatted at 2026-08-12 06:20:14 on dist-test-slave-tc2s"
I20260812 06:20:14.569592 11242 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-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:20:14.576174 11242 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:14.576502 11242 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:14.576891 11242 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:14.577600 11242 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:14.577649 11242 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.577699 11242 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:14.577725 11242 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:14.583789 11242 rpc_server.cc:307] RPC server started. Bound to: 127.10.250.129:38761
I20260812 06:20:14.583832 11511 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.250.129:38761 every 8 connection(s)
I20260812 06:20:14.595108 11512 heartbeater.cc:344] Connected to a master server at 127.10.250.190:41709
I20260812 06:20:14.595335 11512 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:14.595721 11512 heartbeater.cc:507] Master 127.10.250.190:41709 requested a full tablet report, sending...
I20260812 06:20:14.597415 11294 ts_manager.cc:194] Registered new tserver with Master: 0f82ea0b1879460a9eac8a1a2cca2c0a (127.10.250.129:38761)
I20260812 06:20:14.597630 11242 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013285705s
I20260812 06:20:14.598898 11294 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50594
I20260812 06:20:14.606287 11294 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50600:
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:20:14.619686 11441 tablet_service.cc:1511] Processing CreateTablet for tablet 46004bb740b24b7c9b706d77dfea2377 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b44862b4d618433e875ede8dbc0cce2c]), partition=
I20260812 06:20:14.620062 11441 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 46004bb740b24b7c9b706d77dfea2377. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:14.622316 11535 tablet_bootstrap.cc:492] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Bootstrap starting.
I20260812 06:20:14.623337 11535 tablet_bootstrap.cc:654] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:14.624473 11535 tablet_bootstrap.cc:492] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: No bootstrap required, opened a new log
I20260812 06:20:14.624563 11535 ts_tablet_manager.cc:1403] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:14.624940 11535 raft_consensus.cc:359] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f82ea0b1879460a9eac8a1a2cca2c0a" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38761 } }
I20260812 06:20:14.625032 11535 raft_consensus.cc:385] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:14.625065 11535 raft_consensus.cc:740] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0f82ea0b1879460a9eac8a1a2cca2c0a, State: Initialized, Role: FOLLOWER
I20260812 06:20:14.625188 11535 consensus_queue.cc:260] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [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: "0f82ea0b1879460a9eac8a1a2cca2c0a" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38761 } }
I20260812 06:20:14.625281 11535 raft_consensus.cc:399] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:14.625324 11535 raft_consensus.cc:493] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:14.625370 11535 raft_consensus.cc:3060] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:14.626102 11535 raft_consensus.cc:515] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f82ea0b1879460a9eac8a1a2cca2c0a" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38761 } }
I20260812 06:20:14.626228 11535 leader_election.cc:304] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [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: 0f82ea0b1879460a9eac8a1a2cca2c0a; no voters: 
I20260812 06:20:14.626392 11535 leader_election.cc:290] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:14.626503 11540 raft_consensus.cc:2804] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:14.626724 11540 raft_consensus.cc:697] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 1 LEADER]: Becoming Leader. State: Replica: 0f82ea0b1879460a9eac8a1a2cca2c0a, State: Running, Role: LEADER
I20260812 06:20:14.626737 11535 ts_tablet_manager.cc:1434] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:14.626921 11512 heartbeater.cc:499] Master 127.10.250.190:41709 was elected leader, sending a full tablet report...
I20260812 06:20:14.626907 11540 consensus_queue.cc:237] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [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: "0f82ea0b1879460a9eac8a1a2cca2c0a" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38761 } }
I20260812 06:20:14.629601 11294 catalog_manager.cc:5719] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a reported cstate change: term changed from 0 to 1, leader changed from <none> to 0f82ea0b1879460a9eac8a1a2cca2c0a (127.10.250.129). New cstate: current_term: 1 leader_uuid: "0f82ea0b1879460a9eac8a1a2cca2c0a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0f82ea0b1879460a9eac8a1a2cca2c0a" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38761 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:14.707708 11242 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.073s	user 0.015s	sys 0.016s
I20260812 06:20:14.835048 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushMRSOp(46004bb740b24b7c9b706d77dfea2377): perf score=19.054940
I20260812 06:20:14.983669 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushMRSOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.148s	user 0.103s	sys 0.043s Metrics: {"bytes_written":8656348,"cfile_init":1,"compiler_manager_pool.queue_time_us":170,"delete_count":0,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":163,"dirs.run_wall_time_us":674,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36352,"lbm_writes_lt_1ms":668,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":248576,"thread_start_us":89,"threads_started":1,"update_count":1055}
I20260812 06:20:14.984823 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling LogGCOp(46004bb740b24b7c9b706d77dfea2377): free 20743880 bytes of WAL
I20260812 06:20:14.985119 11403 log_reader.cc:385] T 46004bb740b24b7c9b706d77dfea2377: removed 2 log segments from log reader
I20260812 06:20:14.985178 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000001 (ops 1-6)
I20260812 06:20:14.985229 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000002 (ops 7-11)
I20260812 06:20:14.988965 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: LogGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:14.989281 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377): 16411391 bytes on disk
I20260812 06:20:14.989794 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.990211 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:15.008311 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.018s	user 0.001s	sys 0.011s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":5912,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:20:15.008695 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:15.117250 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.108s	user 0.084s	sys 0.020s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":449,"lbm_read_time_us":5697,"lbm_reads_lt_1ms":360,"lbm_write_time_us":19808,"lbm_writes_lt_1ms":343,"mutex_wait_us":34,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":283,"threads_started":5,"update_count":1500}
I20260812 06:20:15.117724 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:15.159081 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.041s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17286,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.159535 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:15.168869 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.169281 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:15.287555 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.118s	user 0.092s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":7700,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22057,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:15.288029 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:15.337139 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.049s	user 0.029s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16799,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.337607 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:15.347460 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.347837 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:15.494282 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.146s	user 0.099s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":6860,"lbm_read_time_us":10264,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23378,"lbm_writes_lt_1ms":443,"mutex_wait_us":2146,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:20:15.494879 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:15.535468 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.040s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13047,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.535956 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:15.545701 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3711,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.546268 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:15.659960 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.113s	user 0.101s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":7897,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21200,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:20:15.660507 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:15.699374 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.039s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14116,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.699822 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:15.714690 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.715176 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:15.837790 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.122s	user 0.118s	sys 0.004s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":7786,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25448,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:15.838282 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:15.879813 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.041s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15469,"lbm_writes_lt_1ms":303,"mutex_wait_us":2,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.880352 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:15.889959 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.009s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.890354 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:16.004264 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.114s	user 0.082s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":7919,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22012,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:20:16.004797 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:16.046607 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.042s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13093,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.047145 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:16.056753 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.057193 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:16.196671 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.139s	user 0.102s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":646,"lbm_read_time_us":9686,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21475,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:20:16.197265 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:16.239692 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.042s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16582,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.240139 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:16.250290 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3685,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.250859 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushMRSOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:16.284281 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushMRSOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1073,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1439,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:16.285092 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling LogGCOp(46004bb740b24b7c9b706d77dfea2377): free 124710294 bytes of WAL
I20260812 06:20:16.285297 11403 log_reader.cc:385] T 46004bb740b24b7c9b706d77dfea2377: removed 12 log segments from log reader
I20260812 06:20:16.285341 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000003 (ops 12-16)
I20260812 06:20:16.285377 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000004 (ops 17-21)
I20260812 06:20:16.285410 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000005 (ops 22-26)
I20260812 06:20:16.285442 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000006 (ops 27-31)
I20260812 06:20:16.285473 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000007 (ops 32-36)
I20260812 06:20:16.285502 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000008 (ops 37-41)
I20260812 06:20:16.285524 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000009 (ops 42-46)
I20260812 06:20:16.285544 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000010 (ops 47-51)
I20260812 06:20:16.285578 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000011 (ops 52-56)
I20260812 06:20:16.285607 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000012 (ops 57-61)
I20260812 06:20:16.285637 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000013 (ops 62-66)
I20260812 06:20:16.285666 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000014 (ops 67-71)
I20260812 06:20:16.307870 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: LogGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:16.308398 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=3.181125
I20260812 06:20:16.327776 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.019s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:16.328203 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:16.337298 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3537,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.337682 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:16.527230 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.189s	user 0.139s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":826,"lbm_read_time_us":15316,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30258,"lbm_writes_lt_1ms":643,"mutex_wait_us":253,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:20:16.527709 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377): 483 bytes on disk
I20260812 06:20:16.528306 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.528815 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:16.579171 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.050s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.579694 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:16.594899 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.595392 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:16.752552 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.157s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1058,"lbm_read_time_us":12173,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29465,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:16.753111 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=11.118625
I20260812 06:20:16.781884 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.029s	user 0.018s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12111,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.782634 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:16.796561 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4870,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.797152 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:16.922482 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":55,"lbm_read_time_us":8709,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22961,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:20:16.923012 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:16.954840 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.032s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13463,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.955358 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:16.969872 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.970367 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:17.091244 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.121s	user 0.099s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":8042,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23370,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:20:17.091733 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:17.130460 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.039s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.130991 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:17.140377 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.140913 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:17.267588 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.126s	user 0.096s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":8189,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25498,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:20:17.268270 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:17.310691 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.042s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14218,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.311189 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:17.320967 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.321363 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:17.458523 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.137s	user 0.097s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":191,"lbm_read_time_us":10207,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23170,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:20:17.459049 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:17.498086 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.039s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14124,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.498580 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:17.513710 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5556,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.514214 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:17.634567 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.120s	user 0.095s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":8824,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23686,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:17.635070 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=10.126437
I20260812 06:20:17.676517 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.041s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17276,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.676956 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:17.686388 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3672,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.686831 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushMRSOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:17.714720 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushMRSOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":154,"dirs.run_wall_time_us":1046,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1562,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:17.715570 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling LogGCOp(46004bb740b24b7c9b706d77dfea2377): free 124710258 bytes of WAL
I20260812 06:20:17.715785 11403 log_reader.cc:385] T 46004bb740b24b7c9b706d77dfea2377: removed 12 log segments from log reader
I20260812 06:20:17.715832 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000015 (ops 72-76)
I20260812 06:20:17.715880 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000016 (ops 77-81)
I20260812 06:20:17.715914 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000017 (ops 82-86)
I20260812 06:20:17.715940 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000018 (ops 87-91)
I20260812 06:20:17.715971 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000019 (ops 92-96)
I20260812 06:20:17.716002 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000020 (ops 97-101)
I20260812 06:20:17.716033 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000021 (ops 102-106)
I20260812 06:20:17.716063 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000022 (ops 107-111)
I20260812 06:20:17.716094 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000023 (ops 112-116)
I20260812 06:20:17.716125 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000024 (ops 117-121)
I20260812 06:20:17.716156 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000025 (ops 122-126)
I20260812 06:20:17.716185 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000026 (ops 127-131)
I20260812 06:20:17.739037 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: LogGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:17.739456 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=3.181125
I20260812 06:20:17.752271 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.013s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4374,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:17.752683 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377): 482 bytes on disk
I20260812 06:20:17.753091 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377) 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:20:17.753574 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:17.766726 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4877,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.767184 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:17.936245 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.169s	user 0.145s	sys 0.015s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":703,"lbm_read_time_us":11331,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33288,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:20:17.937049 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:17.978426 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.041s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17722,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:17.978927 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:17.991135 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.991583 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:18.142448 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.151s	user 0.100s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":8730,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27649,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:20:18.143028 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:18.196669 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.053s	user 0.027s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18553,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.197217 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:18.207196 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3689,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.207854 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:18.372743 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.165s	user 0.107s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":10825,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28311,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:18.373268 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:18.416458 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.043s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18056,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.417021 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:18.559736 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.143s	user 0.095s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":116,"lbm_read_time_us":10363,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22920,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:20:18.560256 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:18.610805 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.050s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":21312,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.611291 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:18.621562 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.622187 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:18.798000 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.176s	user 0.092s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":626,"lbm_read_time_us":11549,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26003,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:18.798468 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:18.839708 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.041s	user 0.034s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.840257 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:18.851598 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.852056 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:19.009004 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.157s	user 0.128s	sys 0.017s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":9951,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28307,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:19.009581 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=14.095187
I20260812 06:20:19.061573 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.052s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26661,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:19.062233 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=2.188937
I20260812 06:20:19.076301 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4823,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.076815 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushMRSOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:19.108958 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushMRSOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1867,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1565,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:19.109792 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling LogGCOp(46004bb740b24b7c9b706d77dfea2377): free 133024698 bytes of WAL
I20260812 06:20:19.110133 11403 log_reader.cc:385] T 46004bb740b24b7c9b706d77dfea2377: removed 13 log segments from log reader
I20260812 06:20:19.110190 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000027 (ops 132-136)
I20260812 06:20:19.110234 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000028 (ops 137-141)
I20260812 06:20:19.110267 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000029 (ops 142-146)
I20260812 06:20:19.110299 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000030 (ops 147-151)
I20260812 06:20:19.110329 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000031 (ops 152-156)
I20260812 06:20:19.110359 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000032 (ops 157-161)
I20260812 06:20:19.110388 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000033 (ops 162-166)
I20260812 06:20:19.110417 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000034 (ops 167-171)
I20260812 06:20:19.110446 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000035 (ops 172-176)
I20260812 06:20:19.110482 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000036 (ops 177-180)
I20260812 06:20:19.110514 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000037 (ops 181-185)
I20260812 06:20:19.110543 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000038 (ops 186-190)
I20260812 06:20:19.110571 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000039 (ops 191-195)
I20260812 06:20:19.134459 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: LogGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.024s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:19.134860 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377): perf score=6.157687
I20260812 06:20:19.166765 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: FlushDeltaMemStoresOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.032s	user 0.022s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11648,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:19.167291 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling LogGCOp(46004bb740b24b7c9b706d77dfea2377): free 12017954 bytes of WAL
I20260812 06:20:19.167770 11403 log_reader.cc:385] T 46004bb740b24b7c9b706d77dfea2377: removed 1 log segments from log reader
I20260812 06:20:19.167820 11403 log.cc:1079] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/46004bb740b24b7c9b706d77dfea2377/wal-000000040 (ops 196-200)
I20260812 06:20:19.169780 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: LogGCOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:19.170079 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377): 492 bytes on disk
I20260812 06:20:19.170459 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: UndoDeltaBlockGCOp(46004bb740b24b7c9b706d77dfea2377) 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:20:19.170998 11513 maintenance_manager.cc:419] P 0f82ea0b1879460a9eac8a1a2cca2c0a: Scheduling MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377): perf score=1.000000
I20260812 06:20:19.196360 11242 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.489s	user 1.678s	sys 0.092s
I20260812 06:20:19.299468 11242 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.000s	sys 0.003s
I20260812 06:20:19.300068 11242 tablet_server.cc:179] TabletServer@127.10.250.129:0 shutting down...
I20260812 06:20:19.362931 11403 maintenance_manager.cc:643] P 0f82ea0b1879460a9eac8a1a2cca2c0a: MajorDeltaCompactionOp(46004bb740b24b7c9b706d77dfea2377) complete. Timing: real 0.192s	user 0.119s	sys 0.072s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1079,"lbm_read_time_us":17333,"lbm_reads_lt_1ms":761,"lbm_write_time_us":30919,"lbm_writes_lt_1ms":743,"mutex_wait_us":254,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":73,"threads_started":1,"update_count":3500}
I20260812 06:20:19.364974 11242 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:19.365698 11242 tablet_replica.cc:333] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a: stopping tablet replica
I20260812 06:20:19.365967 11242 raft_consensus.cc:2243] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.366225 11242 raft_consensus.cc:2272] T 46004bb740b24b7c9b706d77dfea2377 P 0f82ea0b1879460a9eac8a1a2cca2c0a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.370939 11242 tablet_server.cc:196] TabletServer@127.10.250.129:0 shutdown complete.
I20260812 06:20:19.420123 11242 master.cc:562] Master@127.10.250.190:41709 shutting down...
I20260812 06:20:19.423203 11242 raft_consensus.cc:2243] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:19.423375 11242 raft_consensus.cc:2272] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:19.423444 11242 tablet_replica.cc:333] T 00000000000000000000000000000000 P be33ca98b2e34bea87f07898691fd636: stopping tablet replica
I20260812 06:20:19.435380 11242 master.cc:584] Master@127.10.250.190:41709 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5041 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:19.514961 11242 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.250.190:41413
I20260812 06:20:19.515318 11242 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.517113 11567 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:20:19.517191 11569 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:19.517256 11566 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:20:19.517154 11242 server_base.cc:1061] running on GCE node
I20260812 06:20:19.517460 11242 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.517504 11242 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:20:19.517524 11242 hybrid_clock.cc:648] HybridClock initialized: now 1786515619517523 us; error 0 us; skew 500 ppm
I20260812 06:20:19.518306 11242 webserver.cc:533] Webserver started at http://127.10.250.190:33761/ using document root <none> and password file <none>
I20260812 06:20:19.518461 11242 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.518513 11242 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.518591 11242 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.518949 11242 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/master-0-root/instance:
uuid: "81f3b7201a5e4a5f99d40e6352d9419c"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-tc2s"
I20260812 06:20:19.520370 11242 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:19.521236 11577 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:20:19.521430 11242 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.521502 11242 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/master-0-root
uuid: "81f3b7201a5e4a5f99d40e6352d9419c"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-tc2s"
I20260812 06:20:19.521570 11242 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-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:20:19.530092 11242 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.530386 11242 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.534160 11242 rpc_server.cc:307] RPC server started. Bound to: 127.10.250.190:41413
I20260812 06:20:19.540122 11671 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.250.190:41413 every 8 connection(s)
I20260812 06:20:19.540539 11672 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:20:19.542323 11672 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c: Bootstrap starting.
I20260812 06:20:19.543098 11672 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.543957 11672 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c: No bootstrap required, opened a new log
I20260812 06:20:19.544322 11672 raft_consensus.cc:359] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81f3b7201a5e4a5f99d40e6352d9419c" member_type: VOTER }
I20260812 06:20:19.544399 11672 raft_consensus.cc:385] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.544430 11672 raft_consensus.cc:740] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 81f3b7201a5e4a5f99d40e6352d9419c, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.544574 11672 consensus_queue.cc:260] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [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: "81f3b7201a5e4a5f99d40e6352d9419c" member_type: VOTER }
I20260812 06:20:19.544646 11672 raft_consensus.cc:399] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.544684 11672 raft_consensus.cc:493] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.544732 11672 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.545359 11672 raft_consensus.cc:515] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81f3b7201a5e4a5f99d40e6352d9419c" member_type: VOTER }
I20260812 06:20:19.545486 11672 leader_election.cc:304] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [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: 81f3b7201a5e4a5f99d40e6352d9419c; no voters: 
I20260812 06:20:19.545651 11672 leader_election.cc:290] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.545738 11678 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.545964 11678 raft_consensus.cc:697] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 1 LEADER]: Becoming Leader. State: Replica: 81f3b7201a5e4a5f99d40e6352d9419c, State: Running, Role: LEADER
I20260812 06:20:19.546064 11672 sys_catalog.cc:565] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:19.546094 11678 consensus_queue.cc:237] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [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: "81f3b7201a5e4a5f99d40e6352d9419c" member_type: VOTER }
I20260812 06:20:19.546499 11682 sys_catalog.cc:455] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 81f3b7201a5e4a5f99d40e6352d9419c. Latest consensus state: current_term: 1 leader_uuid: "81f3b7201a5e4a5f99d40e6352d9419c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81f3b7201a5e4a5f99d40e6352d9419c" member_type: VOTER } }
I20260812 06:20:19.546584 11682 sys_catalog.cc:458] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.546483 11680 sys_catalog.cc:455] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "81f3b7201a5e4a5f99d40e6352d9419c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81f3b7201a5e4a5f99d40e6352d9419c" member_type: VOTER } }
I20260812 06:20:19.546635 11680 sys_catalog.cc:458] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:19.546833 11685 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:19.547597 11685 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:19.547814 11242 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:19.549328 11685 catalog_manager.cc:1383] Generated new cluster ID: da132b4b10d84a5eb8590dbb767c650b
I20260812 06:20:19.549381 11685 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.559027 11685 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.559501 11685 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.569537 11685 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c: Generated new TSK 0
I20260812 06:20:19.569676 11685 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.579866 11242 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.581507 11703 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:20:19.581564 11704 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:20:19.581606 11242 server_base.cc:1061] running on GCE node
W20260812 06:20:19.581507 11708 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:20:19.581851 11242 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.581915 11242 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:20:19.581956 11242 hybrid_clock.cc:648] HybridClock initialized: now 1786515619581956 us; error 0 us; skew 500 ppm
I20260812 06:20:19.582731 11242 webserver.cc:533] Webserver started at http://127.10.250.129:46609/ using document root <none> and password file <none>
I20260812 06:20:19.582875 11242 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.582921 11242 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.583009 11242 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.583359 11242 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/instance:
uuid: "7f18ef7c98c048f696ac86f01ffe53d2"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-tc2s"
I20260812 06:20:19.584667 11242 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:19.585455 11718 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:20:19.585668 11242 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.585733 11242 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root
uuid: "7f18ef7c98c048f696ac86f01ffe53d2"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-tc2s"
I20260812 06:20:19.585795 11242 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-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:20:19.596421 11242 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.596694 11242 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.596952 11242 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.597353 11242 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.597390 11242 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.597429 11242 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.597457 11242 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.601351 11242 rpc_server.cc:307] RPC server started. Bound to: 127.10.250.129:38577
I20260812 06:20:19.602578 11815 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.250.129:38577 every 8 connection(s)
I20260812 06:20:19.608923 11816 heartbeater.cc:344] Connected to a master server at 127.10.250.190:41413
I20260812 06:20:19.609014 11816 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.609206 11816 heartbeater.cc:507] Master 127.10.250.190:41413 requested a full tablet report, sending...
I20260812 06:20:19.609786 11602 ts_manager.cc:194] Registered new tserver with Master: 7f18ef7c98c048f696ac86f01ffe53d2 (127.10.250.129:38577)
I20260812 06:20:19.610479 11602 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58472
I20260812 06:20:19.610744 11242 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008750952s
I20260812 06:20:19.616807 11602 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58486:
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:20:19.624662 11760 tablet_service.cc:1511] Processing CreateTablet for tablet 779ff4041794424c839e1be9000f703d (DEFAULT_TABLE table=heavy-update-compaction-test [id=b6e8a57f0da0494aa8d76de725272734]), partition=
I20260812 06:20:19.624887 11760 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 779ff4041794424c839e1be9000f703d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.626682 11841 tablet_bootstrap.cc:492] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Bootstrap starting.
I20260812 06:20:19.627646 11841 tablet_bootstrap.cc:654] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.628540 11841 tablet_bootstrap.cc:492] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: No bootstrap required, opened a new log
I20260812 06:20:19.628608 11841 ts_tablet_manager.cc:1403] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:19.628953 11841 raft_consensus.cc:359] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f18ef7c98c048f696ac86f01ffe53d2" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38577 } }
I20260812 06:20:19.629031 11841 raft_consensus.cc:385] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.629057 11841 raft_consensus.cc:740] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7f18ef7c98c048f696ac86f01ffe53d2, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.629161 11841 consensus_queue.cc:260] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [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: "7f18ef7c98c048f696ac86f01ffe53d2" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38577 } }
I20260812 06:20:19.629240 11841 raft_consensus.cc:399] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.629268 11841 raft_consensus.cc:493] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.629303 11841 raft_consensus.cc:3060] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.630000 11841 raft_consensus.cc:515] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f18ef7c98c048f696ac86f01ffe53d2" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38577 } }
I20260812 06:20:19.630141 11841 leader_election.cc:304] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [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: 7f18ef7c98c048f696ac86f01ffe53d2; no voters: 
I20260812 06:20:19.630314 11841 leader_election.cc:290] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.630398 11844 raft_consensus.cc:2804] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.630585 11844 raft_consensus.cc:697] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 1 LEADER]: Becoming Leader. State: Replica: 7f18ef7c98c048f696ac86f01ffe53d2, State: Running, Role: LEADER
I20260812 06:20:19.630622 11841 ts_tablet_manager.cc:1434] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:19.630734 11816 heartbeater.cc:499] Master 127.10.250.190:41413 was elected leader, sending a full tablet report...
I20260812 06:20:19.630719 11844 consensus_queue.cc:237] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [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: "7f18ef7c98c048f696ac86f01ffe53d2" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38577 } }
I20260812 06:20:19.631892 11602 catalog_manager.cc:5719] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7f18ef7c98c048f696ac86f01ffe53d2 (127.10.250.129). New cstate: current_term: 1 leader_uuid: "7f18ef7c98c048f696ac86f01ffe53d2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f18ef7c98c048f696ac86f01ffe53d2" member_type: VOTER last_known_addr { host: "127.10.250.129" port: 38577 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.685184 11242 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.017s	sys 0.004s
I20260812 06:20:19.853039 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushMRSOp(779ff4041794424c839e1be9000f703d): perf score=23.023690
I20260812 06:20:20.005048 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushMRSOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.152s	user 0.094s	sys 0.055s Metrics: {"bytes_written":12471586,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":728,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38619,"lbm_writes_lt_1ms":861,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1280,"update_count":1520}
I20260812 06:20:20.005852 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling LogGCOp(779ff4041794424c839e1be9000f703d): free 20743880 bytes of WAL
I20260812 06:20:20.006116 11724 log_reader.cc:385] T 779ff4041794424c839e1be9000f703d: removed 2 log segments from log reader
I20260812 06:20:20.006181 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000001 (ops 1-6)
I20260812 06:20:20.006280 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000002 (ops 7-11)
I20260812 06:20:20.011209 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: LogGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:20.011521 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d): 20513815 bytes on disk
I20260812 06:20:20.011902 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:20:20.012295 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=3.181125
I20260812 06:20:20.024706 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.012s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4348807,"delete_count":0,"lbm_write_time_us":3933,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:20:20.025163 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:20.162102 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.137s	user 0.092s	sys 0.040s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123516,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":469,"lbm_read_time_us":9430,"lbm_reads_lt_1ms":470,"lbm_write_time_us":21509,"lbm_writes_lt_1ms":453,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":289,"threads_started":5,"update_count":2050}
I20260812 06:20:20.162678 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:20.215065 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.052s	user 0.025s	sys 0.015s Metrics: {"bytes_written":15999661,"delete_count":0,"lbm_write_time_us":17911,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:20:20.215567 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:20.226117 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.226584 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:20.384684 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.158s	user 0.106s	sys 0.052s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24405443,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":541,"lbm_read_time_us":11402,"lbm_reads_lt_1ms":562,"lbm_write_time_us":25146,"lbm_writes_lt_1ms":533,"mutex_wait_us":263,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2450}
I20260812 06:20:20.385210 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:20.436173 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.051s	user 0.024s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":15884,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.436693 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:20.446473 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3857,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.446873 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:20.615949 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.169s	user 0.117s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":11744,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27341,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.616472 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=11.118625
I20260812 06:20:20.646353 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12317,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.646797 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:20.669667 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.023s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.670176 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:20.693197 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.023s	user 0.012s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5678,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.693609 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:20.859126 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.165s	user 0.129s	sys 0.035s 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":381,"lbm_read_time_us":11814,"lbm_reads_lt_1ms":573,"lbm_write_time_us":24744,"lbm_writes_lt_1ms":543,"mutex_wait_us":303,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:20.859648 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=11.118625
I20260812 06:20:20.893146 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.033s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14286,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.893579 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:20.906937 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.013s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3762,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.908078 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:21.034013 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.126s	user 0.097s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1303,"lbm_read_time_us":7063,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22980,"lbm_writes_lt_1ms":443,"mutex_wait_us":258,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:20:21.034530 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=10.126437
I20260812 06:20:21.068327 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.034s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14607,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.068781 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:21.079980 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.080477 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:21.201311 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.121s	user 0.100s	sys 0.020s 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":137,"lbm_read_time_us":7720,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22309,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:20:21.201864 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=10.126437
I20260812 06:20:21.242363 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.040s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13914,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.242920 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:21.252717 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.253201 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushMRSOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:21.285646 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushMRSOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1083,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2190,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:21.286283 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling LogGCOp(779ff4041794424c839e1be9000f703d): free 128867446 bytes of WAL
I20260812 06:20:21.286528 11724 log_reader.cc:385] T 779ff4041794424c839e1be9000f703d: removed 13 log segments from log reader
I20260812 06:20:21.286577 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000003 (ops 12-16)
I20260812 06:20:21.286616 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000004 (ops 17-21)
I20260812 06:20:21.286648 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000005 (ops 22-26)
I20260812 06:20:21.286680 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000006 (ops 27-31)
I20260812 06:20:21.286711 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000007 (ops 32-36)
I20260812 06:20:21.286741 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000008 (ops 37-40)
I20260812 06:20:21.286769 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000009 (ops 41-45)
I20260812 06:20:21.286798 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000010 (ops 46-50)
I20260812 06:20:21.286821 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000011 (ops 51-54)
I20260812 06:20:21.286841 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000012 (ops 55-59)
I20260812 06:20:21.286864 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000013 (ops 60-64)
I20260812 06:20:21.286913 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000014 (ops 65-68)
I20260812 06:20:21.286948 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000015 (ops 69-73)
I20260812 06:20:21.307803 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: LogGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:21.308168 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d): 482 bytes on disk
I20260812 06:20:21.308655 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.309163 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:21.328229 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.019s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6262,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.328675 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:21.342959 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.343374 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:21.511219 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.168s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918332,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1694,"lbm_read_time_us":11730,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33611,"lbm_writes_lt_1ms":643,"mutex_wait_us":357,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:20:21.513986 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:21.552995 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.039s	user 0.015s	sys 0.021s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":17359,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.553424 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:21.565212 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.565826 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:21.718600 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.153s	user 0.107s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":96,"lbm_read_time_us":9462,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31898,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:20:21.719205 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=12.110812
I20260812 06:20:21.757771 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.038s	user 0.030s	sys 0.005s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":16634,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:20:21.758350 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=1.196750
I20260812 06:20:21.774101 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.016s	user 0.006s	sys 0.003s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3529,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:21.774566 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:21.921646 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.147s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713244,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":9778,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22434,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2000}
I20260812 06:20:21.922210 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:21.966215 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.044s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18777,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.966713 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:21.990991 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.024s	user 0.008s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.991488 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:22.163878 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.172s	user 0.089s	sys 0.076s 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":137,"lbm_read_time_us":11807,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25069,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:22.164378 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:22.210346 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20444,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.210841 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:22.227056 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.227648 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:22.406529 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.179s	user 0.124s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":11567,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29147,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:20:22.407137 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:22.453051 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.046s	user 0.016s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17560,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.453624 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:22.469260 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5981,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.469835 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:22.617053 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.147s	user 0.111s	sys 0.034s 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":241,"lbm_read_time_us":10059,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27970,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:20:22.617690 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=11.118625
I20260812 06:20:22.653796 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.036s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15663,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.654392 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:22.670136 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.670727 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushMRSOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:22.724403 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushMRSOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.054s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":37,"dirs.run_cpu_time_us":156,"dirs.run_wall_time_us":1133,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1718,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:22.725051 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling LogGCOp(779ff4041794424c839e1be9000f703d): free 121006462 bytes of WAL
I20260812 06:20:22.725256 11724 log_reader.cc:385] T 779ff4041794424c839e1be9000f703d: removed 12 log segments from log reader
I20260812 06:20:22.725301 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000016 (ops 74-78)
I20260812 06:20:22.725328 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000017 (ops 79-83)
I20260812 06:20:22.725358 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000018 (ops 84-88)
I20260812 06:20:22.725389 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000019 (ops 89-93)
I20260812 06:20:22.725421 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000020 (ops 94-98)
I20260812 06:20:22.725453 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000021 (ops 99-103)
I20260812 06:20:22.725485 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000022 (ops 104-108)
I20260812 06:20:22.725517 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000023 (ops 109-112)
I20260812 06:20:22.725548 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000024 (ops 113-117)
I20260812 06:20:22.725579 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000025 (ops 118-122)
I20260812 06:20:22.725610 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000026 (ops 123-127)
I20260812 06:20:22.725642 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000027 (ops 128-132)
I20260812 06:20:22.745637 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: LogGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:22.746054 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d): 483 bytes on disk
I20260812 06:20:22.746460 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.746981 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=6.157687
I20260812 06:20:22.765554 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7895,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:22.765957 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling LogGCOp(779ff4041794424c839e1be9000f703d): free 12017949 bytes of WAL
I20260812 06:20:22.766230 11724 log_reader.cc:385] T 779ff4041794424c839e1be9000f703d: removed 1 log segments from log reader
I20260812 06:20:22.766275 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000028 (ops 133-137)
I20260812 06:20:22.768157 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: LogGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:22.768462 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:22.779426 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.779899 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:23.001262 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.221s	user 0.133s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":515,"lbm_read_time_us":14001,"lbm_reads_lt_1ms":774,"lbm_write_time_us":35810,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":19584,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:23.001799 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=18.063937
I20260812 06:20:23.054749 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.053s	user 0.028s	sys 0.020s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":22129,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:23.056131 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:23.066854 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.067415 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:23.267637 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.200s	user 0.101s	sys 0.091s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":12729,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32510,"lbm_writes_lt_1ms":643,"mutex_wait_us":5,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:20:23.268522 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=16.079562
I20260812 06:20:23.314198 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.046s	user 0.029s	sys 0.016s Metrics: {"bytes_written":17640628,"delete_count":0,"lbm_write_time_us":19803,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:20:23.314710 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:23.332957 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.018s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3282159,"delete_count":0,"lbm_write_time_us":4925,"lbm_writes_lt_1ms":83,"reinsert_count":0,"update_count":400}
I20260812 06:20:23.333382 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:23.342235 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3424,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.342654 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:23.542030 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.199s	user 0.119s	sys 0.079s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918187,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":723,"lbm_read_time_us":13678,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35090,"lbm_writes_lt_1ms":643,"mutex_wait_us":481,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":30976,"update_count":3000}
I20260812 06:20:23.542526 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:23.587796 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.045s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20111,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.588279 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:23.600458 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.600957 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:23.762791 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.162s	user 0.104s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11064,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28182,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:20:23.763260 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:23.818794 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.055s	user 0.033s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18016,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.819380 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:23.829778 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.830407 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:23.996807 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.166s	user 0.102s	sys 0.064s 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":96,"lbm_read_time_us":12276,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25626,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25472,"update_count":2500}
I20260812 06:20:23.997385 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=14.095187
I20260812 06:20:24.052253 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.055s	user 0.024s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19873,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.052695 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:24.062780 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.063177 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushMRSOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:24.101795 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushMRSOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.038s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1100,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1892,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:24.102545 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling LogGCOp(779ff4041794424c839e1be9000f703d): free 112239560 bytes of WAL
I20260812 06:20:24.102767 11724 log_reader.cc:385] T 779ff4041794424c839e1be9000f703d: removed 11 log segments from log reader
I20260812 06:20:24.102826 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000029 (ops 138-142)
I20260812 06:20:24.102870 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000030 (ops 143-147)
I20260812 06:20:24.102903 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000031 (ops 148-152)
I20260812 06:20:24.102937 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000032 (ops 153-156)
I20260812 06:20:24.102967 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000033 (ops 157-161)
I20260812 06:20:24.102994 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000034 (ops 162-166)
I20260812 06:20:24.103022 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000035 (ops 167-171)
I20260812 06:20:24.103051 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000036 (ops 172-176)
I20260812 06:20:24.103083 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000037 (ops 177-181)
I20260812 06:20:24.103113 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000038 (ops 182-186)
I20260812 06:20:24.103142 11724 log.cc:1079] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: Deleting log segment in path: /tmp/dist-test-taskTUzz0Z/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515614452962-11242-0/minicluster-data/ts-0-root/wals/779ff4041794424c839e1be9000f703d/wal-000000039 (ops 187-191)
I20260812 06:20:24.129031 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: LogGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:24.129385 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d): 462 bytes on disk
I20260812 06:20:24.129779 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: UndoDeltaBlockGCOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:24.130334 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=3.181125
I20260812 06:20:24.149386 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.019s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4340,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:24.149746 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d): perf score=2.188937
I20260812 06:20:24.159188 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: FlushDeltaMemStoresOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3618,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:24.159600 11818 maintenance_manager.cc:419] P 7f18ef7c98c048f696ac86f01ffe53d2: Scheduling MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d): perf score=1.000000
I20260812 06:20:24.236842 11242 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.552s	user 1.705s	sys 0.130s
I20260812 06:20:24.324728 11242 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.001s	sys 0.000s
I20260812 06:20:24.325214 11242 tablet_server.cc:179] TabletServer@127.10.250.129:0 shutting down...
I20260812 06:20:24.357682 11724 maintenance_manager.cc:643] P 7f18ef7c98c048f696ac86f01ffe53d2: MajorDeltaCompactionOp(779ff4041794424c839e1be9000f703d) complete. Timing: real 0.198s	user 0.118s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":229,"lbm_read_time_us":14299,"lbm_reads_lt_1ms":770,"lbm_write_time_us":30099,"lbm_writes_lt_1ms":743,"mutex_wait_us":46,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":45440,"thread_start_us":65,"threads_started":1,"update_count":3500}
I20260812 06:20:24.359129 11242 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.359501 11242 tablet_replica.cc:333] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2: stopping tablet replica
I20260812 06:20:24.359633 11242 raft_consensus.cc:2243] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.359797 11242 raft_consensus.cc:2272] T 779ff4041794424c839e1be9000f703d P 7f18ef7c98c048f696ac86f01ffe53d2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.364030 11242 tablet_server.cc:196] TabletServer@127.10.250.129:0 shutdown complete.
I20260812 06:20:24.414556 11242 master.cc:562] Master@127.10.250.190:41413 shutting down...
I20260812 06:20:24.417310 11242 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.417467 11242 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.417515 11242 tablet_replica.cc:333] T 00000000000000000000000000000000 P 81f3b7201a5e4a5f99d40e6352d9419c: stopping tablet replica
I20260812 06:20:24.429539 11242 master.cc:584] Master@127.10.250.190:41413 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4995 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10037 ms total)

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