[==========] 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:16:56.635994 17936 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.132.62:45069
I20260812 06:16:56.637032 17936 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:16:56.637668 17936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.644040 17944 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:16:56.644050 17943 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:16:56.644291 17936 server_base.cc:1061] running on GCE node
W20260812 06:16:56.644405 17949 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:16:56.644966 17936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.645080 17936 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:16:56.645134 17936 hybrid_clock.cc:648] HybridClock initialized: now 1786515416645128 us; error 0 us; skew 500 ppm
I20260812 06:16:56.647042 17936 webserver.cc:533] Webserver started at http://127.17.132.62:45689/ using document root <none> and password file <none>
I20260812 06:16:56.647624 17936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.647712 17936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.647985 17936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.649749 17936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/master-0-root/instance:
uuid: "a7e2c8d9370a4e3b989cea9283e99fbb"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-zr1t"
I20260812 06:16:56.653261 17936 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:16:56.655392 17961 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:16:56.656407 17936 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:56.656543 17936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/master-0-root
uuid: "a7e2c8d9370a4e3b989cea9283e99fbb"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-zr1t"
I20260812 06:16:56.656647 17936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-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:16:56.678258 17936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.679059 17936 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:16:56.679268 17936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.687250 17936 rpc_server.cc:307] RPC server started. Bound to: 127.17.132.62:45069
I20260812 06:16:56.687263 18058 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.132.62:45069 every 8 connection(s)
I20260812 06:16:56.689702 18060 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:16:56.695147 18060 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb: Bootstrap starting.
I20260812 06:16:56.697480 18060 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.698410 18060 log.cc:826] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:56.700115 18060 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb: No bootstrap required, opened a new log
I20260812 06:16:56.702895 18060 raft_consensus.cc:359] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7e2c8d9370a4e3b989cea9283e99fbb" member_type: VOTER }
I20260812 06:16:56.703056 18060 raft_consensus.cc:385] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.703105 18060 raft_consensus.cc:740] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a7e2c8d9370a4e3b989cea9283e99fbb, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.703636 18060 consensus_queue.cc:260] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [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: "a7e2c8d9370a4e3b989cea9283e99fbb" member_type: VOTER }
I20260812 06:16:56.703763 18060 raft_consensus.cc:399] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.703809 18060 raft_consensus.cc:493] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.703891 18060 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.704615 18060 raft_consensus.cc:515] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7e2c8d9370a4e3b989cea9283e99fbb" member_type: VOTER }
I20260812 06:16:56.704996 18060 leader_election.cc:304] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [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: a7e2c8d9370a4e3b989cea9283e99fbb; no voters: 
I20260812 06:16:56.705261 18060 leader_election.cc:290] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.705502 18064 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.705817 18064 raft_consensus.cc:697] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 1 LEADER]: Becoming Leader. State: Replica: a7e2c8d9370a4e3b989cea9283e99fbb, State: Running, Role: LEADER
I20260812 06:16:56.706189 18064 consensus_queue.cc:237] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [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: "a7e2c8d9370a4e3b989cea9283e99fbb" member_type: VOTER }
I20260812 06:16:56.706403 18060 sys_catalog.cc:565] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:56.708175 18066 sys_catalog.cc:455] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a7e2c8d9370a4e3b989cea9283e99fbb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7e2c8d9370a4e3b989cea9283e99fbb" member_type: VOTER } }
I20260812 06:16:56.708206 18068 sys_catalog.cc:455] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [sys.catalog]: SysCatalogTable state changed. Reason: New leader a7e2c8d9370a4e3b989cea9283e99fbb. Latest consensus state: current_term: 1 leader_uuid: "a7e2c8d9370a4e3b989cea9283e99fbb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a7e2c8d9370a4e3b989cea9283e99fbb" member_type: VOTER } }
I20260812 06:16:56.708333 18068 sys_catalog.cc:458] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.708335 18066 sys_catalog.cc:458] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:56.708787 17936 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:56.708742 18088 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:56.711465 18088 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:56.716130 18088 catalog_manager.cc:1383] Generated new cluster ID: 809b3291527d4a06bd3e628c6d112c06
I20260812 06:16:56.716264 18088 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:56.732790 18088 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:56.733776 18088 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:56.743450 18088 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb: Generated new TSK 0
I20260812 06:16:56.744139 18088 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:56.773772 17936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:56.777070 18107 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:16:56.777159 17936 server_base.cc:1061] running on GCE node
W20260812 06:16:56.776993 18102 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:16:56.776986 18103 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:16:56.777688 17936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:56.777767 17936 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:16:56.777789 17936 hybrid_clock.cc:648] HybridClock initialized: now 1786515416777789 us; error 0 us; skew 500 ppm
I20260812 06:16:56.778699 17936 webserver.cc:533] Webserver started at http://127.17.132.1:41323/ using document root <none> and password file <none>
I20260812 06:16:56.778898 17936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:56.778947 17936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:56.779057 17936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:56.779474 17936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/instance:
uuid: "65210e6eac4349ae8968b8fc66725e27"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-zr1t"
I20260812 06:16:56.781026 17936 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:56.782078 18117 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:16:56.782333 17936 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:16:56.782408 17936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root
uuid: "65210e6eac4349ae8968b8fc66725e27"
format_stamp: "Formatted at 2026-08-12 06:16:56 on dist-test-slave-zr1t"
I20260812 06:16:56.782507 17936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-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:16:56.796629 17936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:56.797098 17936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:56.797693 17936 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:56.798599 17936 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:56.798651 17936 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:56.798725 17936 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:56.798763 17936 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:56.807917 17936 rpc_server.cc:307] RPC server started. Bound to: 127.17.132.1:39969
I20260812 06:16:56.808018 18236 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.132.1:39969 every 8 connection(s)
I20260812 06:16:56.818460 18237 heartbeater.cc:344] Connected to a master server at 127.17.132.62:45069
I20260812 06:16:56.818709 18237 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:56.819165 18237 heartbeater.cc:507] Master 127.17.132.62:45069 requested a full tablet report, sending...
I20260812 06:16:56.820900 17997 ts_manager.cc:194] Registered new tserver with Master: 65210e6eac4349ae8968b8fc66725e27 (127.17.132.1:39969)
I20260812 06:16:56.821126 17936 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012346733s
I20260812 06:16:56.822897 17997 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57090
I20260812 06:16:56.831888 17997 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57092:
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:16:56.851625 18173 tablet_service.cc:1511] Processing CreateTablet for tablet 257ab653ce7d4a78a8067eb648d47d4d (DEFAULT_TABLE table=heavy-update-compaction-test [id=c23d3569f14643dba5644e49abbf1077]), partition=
I20260812 06:16:56.852108 18173 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 257ab653ce7d4a78a8067eb648d47d4d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:56.855481 18258 tablet_bootstrap.cc:492] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Bootstrap starting.
I20260812 06:16:56.857832 18258 tablet_bootstrap.cc:654] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:56.859645 18258 tablet_bootstrap.cc:492] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: No bootstrap required, opened a new log
I20260812 06:16:56.859772 18258 ts_tablet_manager.cc:1403] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Time spent bootstrapping tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:16:56.860562 18258 raft_consensus.cc:359] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65210e6eac4349ae8968b8fc66725e27" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 39969 } }
I20260812 06:16:56.860692 18258 raft_consensus.cc:385] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:56.860746 18258 raft_consensus.cc:740] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 65210e6eac4349ae8968b8fc66725e27, State: Initialized, Role: FOLLOWER
I20260812 06:16:56.860939 18258 consensus_queue.cc:260] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [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: "65210e6eac4349ae8968b8fc66725e27" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 39969 } }
I20260812 06:16:56.861126 18258 raft_consensus.cc:399] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:56.861181 18258 raft_consensus.cc:493] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:56.861238 18258 raft_consensus.cc:3060] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:56.862833 18258 raft_consensus.cc:515] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65210e6eac4349ae8968b8fc66725e27" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 39969 } }
I20260812 06:16:56.862996 18258 leader_election.cc:304] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [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: 65210e6eac4349ae8968b8fc66725e27; no voters: 
I20260812 06:16:56.863238 18258 leader_election.cc:290] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:56.863435 18260 raft_consensus.cc:2804] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:56.863669 18258 ts_tablet_manager.cc:1434] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Time spent starting tablet: real 0.004s	user 0.002s	sys 0.003s
I20260812 06:16:56.863862 18260 raft_consensus.cc:697] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 1 LEADER]: Becoming Leader. State: Replica: 65210e6eac4349ae8968b8fc66725e27, State: Running, Role: LEADER
I20260812 06:16:56.863994 18237 heartbeater.cc:499] Master 127.17.132.62:45069 was elected leader, sending a full tablet report...
I20260812 06:16:56.864101 18260 consensus_queue.cc:237] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [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: "65210e6eac4349ae8968b8fc66725e27" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 39969 } }
I20260812 06:16:56.867481 17997 catalog_manager.cc:5719] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 reported cstate change: term changed from 0 to 1, leader changed from <none> to 65210e6eac4349ae8968b8fc66725e27 (127.17.132.1). New cstate: current_term: 1 leader_uuid: "65210e6eac4349ae8968b8fc66725e27" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "65210e6eac4349ae8968b8fc66725e27" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 39969 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:57.025262 17936 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.147s	user 0.021s	sys 0.026s
I20260812 06:16:57.059204 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=3.179940
I20260812 06:16:57.151046 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.091s	user 0.062s	sys 0.028s Metrics: {"bytes_written":3692405,"cfile_init":1,"compiler_manager_pool.queue_time_us":340,"delete_count":0,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":786,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":21800,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":156,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"thread_start_us":241,"threads_started":1,"update_count":450}
I20260812 06:16:57.152061 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d): 411734 bytes on disk
I20260812 06:16:57.152595 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d) 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:16:57.152977 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=0.891874
I20260812 06:16:57.277495 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.124s	user 0.084s	sys 0.040s Metrics: {"cfile_cache_miss":121,"cfile_cache_miss_bytes":7831772,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":324,"lbm_read_time_us":4214,"lbm_reads_lt_1ms":153,"lbm_write_time_us":41448,"lbm_writes_1-10_ms":9,"lbm_writes_lt_1ms":124,"peak_mem_usage":11958878,"reinsert_count":0,"thread_start_us":434,"threads_started":5,"update_count":450}
I20260812 06:16:57.278072 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=3.181125
I20260812 06:16:57.310256 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.032s	user 0.012s	sys 0.019s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":20856,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:57.310796 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:57.360569 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.050s	user 0.010s	sys 0.020s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":21291,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.361157 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:57.485034 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.124s	user 0.064s	sys 0.047s Metrics: {"cfile_cache_miss":232,"cfile_cache_miss_bytes":12344547,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":347,"lbm_read_time_us":4703,"lbm_reads_lt_1ms":264,"lbm_write_time_us":27688,"lbm_writes_lt_1ms":243,"mutex_wait_us":24,"peak_mem_usage":25836184,"reinsert_count":0,"spinlock_wait_cycles":672896,"update_count":1000}
I20260812 06:16:57.485719 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:57.530789 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.045s	user 0.026s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16543,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.531322 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:57.543005 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.543503 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:57.699766 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.156s	user 0.095s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":11064,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26214,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22912,"update_count":2000}
I20260812 06:16:57.700352 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:57.748697 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.048s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16768,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.749142 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:57.760221 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.761031 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:57.888404 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.127s	user 0.103s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549384,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1068,"lbm_read_time_us":8286,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26733,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:16:57.888890 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:57.929582 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.041s	user 0.011s	sys 0.027s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17959,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:57.930078 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:57.941663 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4475,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.942163 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:58.067998 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.126s	user 0.087s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":109,"lbm_read_time_us":9502,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27219,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:16:58.071728 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=11.118625
I20260812 06:16:58.113797 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.042s	user 0.031s	sys 0.011s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15265,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.114346 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:58.124539 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.010s	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:16:58.126564 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:58.278071 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.151s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549375,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":968,"lbm_read_time_us":11529,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26426,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":70016,"update_count":2000}
I20260812 06:16:58.278734 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:58.321835 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.043s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17391,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.322372 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:58.333437 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.334195 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:58.465703 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.131s	user 0.082s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":703,"lbm_read_time_us":10021,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27092,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:16:58.468325 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:58.506246 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.037s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17092,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.506772 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:58.520387 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5345,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.520849 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:58.653649 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.133s	user 0.100s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":733,"lbm_read_time_us":9601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25341,"lbm_writes_lt_1ms":443,"mutex_wait_us":71,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:16:58.654314 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=11.118625
I20260812 06:16:58.689381 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.035s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15170,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:58.689945 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:58.711381 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.021s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3925,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.711877 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:58.722007 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.722478 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:58.750932 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1233,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1677,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:58.751801 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling LogGCOp(257ab653ce7d4a78a8067eb648d47d4d): free 128826237 bytes of WAL
I20260812 06:16:58.752117 18124 log_reader.cc:385] T 257ab653ce7d4a78a8067eb648d47d4d: removed 13 log segments from log reader
I20260812 06:16:58.752204 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000001 (ops 1-6)
I20260812 06:16:58.752297 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000002 (ops 7-10)
I20260812 06:16:58.752357 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000003 (ops 11-15)
I20260812 06:16:58.752400 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000004 (ops 16-20)
I20260812 06:16:58.752447 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000005 (ops 21-24)
I20260812 06:16:58.752483 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000006 (ops 25-29)
I20260812 06:16:58.752523 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000007 (ops 30-34)
I20260812 06:16:58.752561 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000008 (ops 35-39)
I20260812 06:16:58.752599 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000009 (ops 40-44)
I20260812 06:16:58.752636 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000010 (ops 45-49)
I20260812 06:16:58.752674 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000011 (ops 50-54)
I20260812 06:16:58.752712 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000012 (ops 55-58)
I20260812 06:16:58.752750 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000013 (ops 59-63)
I20260812 06:16:58.780597 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: LogGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:58.781061 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d): 482 bytes on disk
I20260812 06:16:58.781659 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:16:58.782250 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=3.181125
I20260812 06:16:58.795528 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5136,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:58.795974 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling LogGCOp(257ab653ce7d4a78a8067eb648d47d4d): free 12017983 bytes of WAL
I20260812 06:16:58.796236 18124 log_reader.cc:385] T 257ab653ce7d4a78a8067eb648d47d4d: removed 1 log segments from log reader
I20260812 06:16:58.796301 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000014 (ops 64-68)
I20260812 06:16:58.799738 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: LogGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:58.800052 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:58.814798 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:58.815322 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:59.028770 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.213s	user 0.159s	sys 0.052s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32856956,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3028,"lbm_read_time_us":16512,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41454,"lbm_writes_lt_1ms":743,"mutex_wait_us":366,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:16:59.029536 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=15.087375
I20260812 06:16:59.093739 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.064s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":21940,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:59.094255 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=6.157687
I20260812 06:16:59.118762 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.024s	user 0.010s	sys 0.009s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":8893,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:59.119315 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:59.285694 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.166s	user 0.118s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28754206,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":105,"lbm_read_time_us":12826,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33457,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:16:59.286645 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:16:59.334164 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.047s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21249,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.334705 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:59.349823 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.350261 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:59.519263 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.169s	user 0.117s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":12204,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34086,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:16:59.519804 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:16:59.562683 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.043s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19686,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.563287 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:59.716215 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.153s	user 0.111s	sys 0.039s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20549261,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":343,"lbm_read_time_us":11981,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26376,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:16:59.716904 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:59.747884 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.031s	user 0.024s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14154,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.748337 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:59.765805 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.766400 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:16:59.902056 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.135s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":8377,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26775,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:16:59.902860 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:16:59.940124 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16828,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.940629 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:16:59.957449 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7146,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.958058 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:00.081012 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.123s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":8274,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25076,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:17:00.082069 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=10.126437
I20260812 06:17:00.124955 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.042s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17073,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:00.125468 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:00.135985 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.136855 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:00.168890 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1150,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1345,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:00.169718 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling LogGCOp(257ab653ce7d4a78a8067eb648d47d4d): free 108535399 bytes of WAL
I20260812 06:17:00.169970 18124 log_reader.cc:385] T 257ab653ce7d4a78a8067eb648d47d4d: removed 11 log segments from log reader
I20260812 06:17:00.170032 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000015 (ops 69-73)
I20260812 06:17:00.170073 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000016 (ops 74-78)
I20260812 06:17:00.170107 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000017 (ops 79-82)
I20260812 06:17:00.170130 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000018 (ops 83-87)
I20260812 06:17:00.170162 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000019 (ops 88-92)
I20260812 06:17:00.170192 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000020 (ops 93-96)
I20260812 06:17:00.170236 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000021 (ops 97-101)
I20260812 06:17:00.170269 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000022 (ops 102-106)
I20260812 06:17:00.170308 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000023 (ops 107-111)
I20260812 06:17:00.170336 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000024 (ops 112-116)
I20260812 06:17:00.170367 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000025 (ops 117-121)
I20260812 06:17:00.198484 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: LogGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:00.198896 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:00.220561 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.021s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.220983 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling LogGCOp(257ab653ce7d4a78a8067eb648d47d4d): free 12017981 bytes of WAL
I20260812 06:17:00.221186 18124 log_reader.cc:385] T 257ab653ce7d4a78a8067eb648d47d4d: removed 1 log segments from log reader
I20260812 06:17:00.221232 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000026 (ops 122-126)
I20260812 06:17:00.223897 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: LogGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:00.224224 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d): 463 bytes on disk
I20260812 06:17:00.224619 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.225106 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:00.237460 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.238003 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:00.412935 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.175s	user 0.134s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754445,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":572,"lbm_read_time_us":13705,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34155,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:17:00.413651 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:17:00.466467 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.053s	user 0.032s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22126,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.466949 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:00.477851 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.478297 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:00.645084 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.167s	user 0.100s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":9498,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31852,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:17:00.645712 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:17:00.690666 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.045s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20040,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.691092 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:00.830513 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.139s	user 0.087s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20549263,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":373,"lbm_read_time_us":9463,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25332,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:00.831123 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=11.118625
I20260812 06:17:00.867805 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.036s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15873,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:00.868552 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:00.895183 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.026s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5554,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:00.895694 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:00.906127 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.906601 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:01.096467 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.190s	user 0.134s	sys 0.050s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24651903,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":174,"lbm_read_time_us":12034,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32420,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:01.097177 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:17:01.146312 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.049s	user 0.041s	sys 0.007s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22300,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.146816 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:01.160506 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.161165 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:01.314989 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.154s	user 0.125s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651791,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":561,"lbm_read_time_us":9051,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31216,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":60928,"update_count":2500}
I20260812 06:17:01.315704 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:17:01.362412 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.047s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20353,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.362914 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:01.374221 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.376286 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:01.545178 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.169s	user 0.113s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":10446,"lbm_reads_lt_1ms":572,"lbm_write_time_us":56234,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":540,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:17:01.545811 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=14.095187
I20260812 06:17:01.596880 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.051s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22389,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.597445 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:01.612792 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.613363 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:01.646953 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushMRSOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1272,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1577,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:01.647660 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling LogGCOp(257ab653ce7d4a78a8067eb648d47d4d): free 120553628 bytes of WAL
I20260812 06:17:01.647883 18124 log_reader.cc:385] T 257ab653ce7d4a78a8067eb648d47d4d: removed 12 log segments from log reader
I20260812 06:17:01.647929 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000027 (ops 127-131)
I20260812 06:17:01.647957 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000028 (ops 132-136)
I20260812 06:17:01.648011 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000029 (ops 137-140)
I20260812 06:17:01.648057 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000030 (ops 141-145)
I20260812 06:17:01.648088 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000031 (ops 146-150)
I20260812 06:17:01.648131 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000032 (ops 151-155)
I20260812 06:17:01.648172 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000033 (ops 156-160)
I20260812 06:17:01.648211 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000034 (ops 161-165)
I20260812 06:17:01.648249 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000035 (ops 166-170)
I20260812 06:17:01.648289 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000036 (ops 171-175)
I20260812 06:17:01.648329 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000037 (ops 176-180)
I20260812 06:17:01.648370 18124 log.cc:1079] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/257ab653ce7d4a78a8067eb648d47d4d/wal-000000038 (ops 181-184)
I20260812 06:17:01.673463 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: LogGCOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:01.673988 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d): 482 bytes on disk
I20260812 06:17:01.674393 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: UndoDeltaBlockGCOp(257ab653ce7d4a78a8067eb648d47d4d) 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:17:01.674911 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=4.173312
I20260812 06:17:01.691897 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.017s	user 0.002s	sys 0.013s Metrics: {"bytes_written":5702609,"delete_count":0,"lbm_write_time_us":7087,"lbm_writes_lt_1ms":142,"reinsert_count":0,"update_count":695}
I20260812 06:17:01.692364 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.196750
I20260812 06:17:01.703969 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":4261,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:17:01.704591 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:01.946349 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.242s	user 0.147s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32856818,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":567,"lbm_read_time_us":16177,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40841,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9344,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:17:01.946947 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=18.063937
I20260812 06:17:02.001763 17936 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.976s	user 1.809s	sys 0.103s
I20260812 06:17:02.013000 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.066s	user 0.027s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26352,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:02.013427 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=2.188937
I20260812 06:17:02.023314 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: FlushDeltaMemStoresOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":500}
I20260812 06:17:02.023744 18238 maintenance_manager.cc:419] P 65210e6eac4349ae8968b8fc66725e27: Scheduling MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d): perf score=1.000000
I20260812 06:17:02.086648 17936 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.005s	sys 0.000s
I20260812 06:17:02.087409 17936 tablet_server.cc:179] TabletServer@127.17.132.1:0 shutting down...
I20260812 06:17:02.172781 18124 maintenance_manager.cc:643] P 65210e6eac4349ae8968b8fc66725e27: MajorDeltaCompactionOp(257ab653ce7d4a78a8067eb648d47d4d) complete. Timing: real 0.149s	user 0.108s	sys 0.040s Metrics: {"cfile_cache_hit":262,"cfile_cache_hit_bytes":10710553,"cfile_cache_miss":370,"cfile_cache_miss_bytes":18043655,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":8499,"lbm_reads_lt_1ms":402,"lbm_write_time_us":30069,"lbm_writes_lt_1ms":643,"mutex_wait_us":36,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":60928,"update_count":3000}
I20260812 06:17:02.173539 17936 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:02.173938 17936 tablet_replica.cc:333] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27: stopping tablet replica
I20260812 06:17:02.174190 17936 raft_consensus.cc:2243] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.174427 17936 raft_consensus.cc:2272] T 257ab653ce7d4a78a8067eb648d47d4d P 65210e6eac4349ae8968b8fc66725e27 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.190003 17936 tablet_server.cc:196] TabletServer@127.17.132.1:0 shutdown complete.
I20260812 06:17:02.228101 17936 master.cc:562] Master@127.17.132.62:45069 shutting down...
I20260812 06:17:02.231892 17936 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.232101 17936 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.232204 17936 tablet_replica.cc:333] T 00000000000000000000000000000000 P a7e2c8d9370a4e3b989cea9283e99fbb: stopping tablet replica
I20260812 06:17:02.244619 17936 master.cc:584] Master@127.17.132.62:45069 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5703 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:02.351831 17936 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.132.62:40543
I20260812 06:17:02.352247 17936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.354347 18297 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:17:02.354445 18295 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:17:02.354447 18294 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:17:02.354631 17936 server_base.cc:1061] running on GCE node
I20260812 06:17:02.354811 17936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.354864 17936 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:17:02.354898 17936 hybrid_clock.cc:648] HybridClock initialized: now 1786515422354897 us; error 0 us; skew 500 ppm
I20260812 06:17:02.355746 17936 webserver.cc:533] Webserver started at http://127.17.132.62:38025/ using document root <none> and password file <none>
I20260812 06:17:02.355937 17936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.356015 17936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.356098 17936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.356518 17936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/master-0-root/instance:
uuid: "ec2ca7503e3b4c15a4f13d78703191e1"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-zr1t"
I20260812 06:17:02.358151 17936 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:02.359119 18306 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:17:02.359396 17936 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:02.359491 17936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/master-0-root
uuid: "ec2ca7503e3b4c15a4f13d78703191e1"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-zr1t"
I20260812 06:17:02.359578 17936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-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:17:02.367166 17936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.367494 17936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.372251 17936 rpc_server.cc:307] RPC server started. Bound to: 127.17.132.62:40543
I20260812 06:17:02.374158 18391 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:17:02.374749 18390 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.132.62:40543 every 8 connection(s)
I20260812 06:17:02.378183 18391 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1: Bootstrap starting.
I20260812 06:17:02.378957 18391 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.379911 18391 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1: No bootstrap required, opened a new log
I20260812 06:17:02.380314 18391 raft_consensus.cc:359] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec2ca7503e3b4c15a4f13d78703191e1" member_type: VOTER }
I20260812 06:17:02.380422 18391 raft_consensus.cc:385] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.380473 18391 raft_consensus.cc:740] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ec2ca7503e3b4c15a4f13d78703191e1, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.380625 18391 consensus_queue.cc:260] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [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: "ec2ca7503e3b4c15a4f13d78703191e1" member_type: VOTER }
I20260812 06:17:02.380718 18391 raft_consensus.cc:399] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.380766 18391 raft_consensus.cc:493] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.380824 18391 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.381505 18391 raft_consensus.cc:515] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec2ca7503e3b4c15a4f13d78703191e1" member_type: VOTER }
I20260812 06:17:02.381683 18391 leader_election.cc:304] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [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: ec2ca7503e3b4c15a4f13d78703191e1; no voters: 
I20260812 06:17:02.381886 18391 leader_election.cc:290] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.381965 18397 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.382252 18397 raft_consensus.cc:697] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 1 LEADER]: Becoming Leader. State: Replica: ec2ca7503e3b4c15a4f13d78703191e1, State: Running, Role: LEADER
I20260812 06:17:02.382370 18391 sys_catalog.cc:565] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:02.382404 18397 consensus_queue.cc:237] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [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: "ec2ca7503e3b4c15a4f13d78703191e1" member_type: VOTER }
I20260812 06:17:02.382881 18400 sys_catalog.cc:455] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader ec2ca7503e3b4c15a4f13d78703191e1. Latest consensus state: current_term: 1 leader_uuid: "ec2ca7503e3b4c15a4f13d78703191e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec2ca7503e3b4c15a4f13d78703191e1" member_type: VOTER } }
I20260812 06:17:02.383008 18400 sys_catalog.cc:458] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.382861 18399 sys_catalog.cc:455] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ec2ca7503e3b4c15a4f13d78703191e1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ec2ca7503e3b4c15a4f13d78703191e1" member_type: VOTER } }
I20260812 06:17:02.383263 18399 sys_catalog.cc:458] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.383358 18407 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:02.384084 18407 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:02.384397 17936 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:02.385936 18407 catalog_manager.cc:1383] Generated new cluster ID: 14380019c48b4e24abe5427262864d3f
I20260812 06:17:02.386004 18407 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:02.398347 18407 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:02.398871 18407 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:02.405710 18407 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1: Generated new TSK 0
I20260812 06:17:02.405892 18407 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:02.416635 17936 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.418431 18435 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:17:02.418541 18432 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:17:02.418541 18438 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:17:02.418751 17936 server_base.cc:1061] running on GCE node
I20260812 06:17:02.418977 17936 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.419018 17936 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:17:02.419034 17936 hybrid_clock.cc:648] HybridClock initialized: now 1786515422419034 us; error 0 us; skew 500 ppm
I20260812 06:17:02.419932 17936 webserver.cc:533] Webserver started at http://127.17.132.1:39347/ using document root <none> and password file <none>
I20260812 06:17:02.420111 17936 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.420183 17936 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.420265 17936 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.420656 17936 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/instance:
uuid: "ff2c78297c5745968b36d72475bf3539"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-zr1t"
I20260812 06:17:02.422191 17936 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:02.423118 18448 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:17:02.423382 17936 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:02.423445 17936 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root
uuid: "ff2c78297c5745968b36d72475bf3539"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-zr1t"
I20260812 06:17:02.423545 17936 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-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:17:02.434581 17936 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.434921 17936 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.435213 17936 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:02.435693 17936 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:02.435755 17936 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.435815 17936 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:02.435849 17936 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.440268 17936 rpc_server.cc:307] RPC server started. Bound to: 127.17.132.1:45529
I20260812 06:17:02.440299 18559 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.132.1:45529 every 8 connection(s)
I20260812 06:17:02.450371 18561 heartbeater.cc:344] Connected to a master server at 127.17.132.62:40543
I20260812 06:17:02.450480 18561 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:02.450717 18561 heartbeater.cc:507] Master 127.17.132.62:40543 requested a full tablet report, sending...
I20260812 06:17:02.451361 18331 ts_manager.cc:194] Registered new tserver with Master: ff2c78297c5745968b36d72475bf3539 (127.17.132.1:45529)
I20260812 06:17:02.451694 17936 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010971382s
I20260812 06:17:02.452142 18331 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51984
I20260812 06:17:02.458436 18331 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51990:
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:17:02.466877 18501 tablet_service.cc:1511] Processing CreateTablet for tablet d559f96fedda4134989f367d7a5f8ce3 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f56d198e33f647afa509bfd4d4f2d165]), partition=
I20260812 06:17:02.467162 18501 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d559f96fedda4134989f367d7a5f8ce3. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:02.469049 18591 tablet_bootstrap.cc:492] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Bootstrap starting.
I20260812 06:17:02.469993 18591 tablet_bootstrap.cc:654] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.471022 18591 tablet_bootstrap.cc:492] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: No bootstrap required, opened a new log
I20260812 06:17:02.471095 18591 ts_tablet_manager.cc:1403] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:02.471499 18591 raft_consensus.cc:359] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c78297c5745968b36d72475bf3539" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 45529 } }
I20260812 06:17:02.471583 18591 raft_consensus.cc:385] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.471643 18591 raft_consensus.cc:740] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ff2c78297c5745968b36d72475bf3539, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.471797 18591 consensus_queue.cc:260] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [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: "ff2c78297c5745968b36d72475bf3539" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 45529 } }
I20260812 06:17:02.471910 18591 raft_consensus.cc:399] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.471961 18591 raft_consensus.cc:493] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.472019 18591 raft_consensus.cc:3060] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.472863 18591 raft_consensus.cc:515] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c78297c5745968b36d72475bf3539" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 45529 } }
I20260812 06:17:02.473021 18591 leader_election.cc:304] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [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: ff2c78297c5745968b36d72475bf3539; no voters: 
I20260812 06:17:02.473277 18591 leader_election.cc:290] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.473340 18593 raft_consensus.cc:2804] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.473718 18561 heartbeater.cc:499] Master 127.17.132.62:40543 was elected leader, sending a full tablet report...
I20260812 06:17:02.473698 18591 ts_tablet_manager.cc:1434] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:02.473961 18593 raft_consensus.cc:697] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 1 LEADER]: Becoming Leader. State: Replica: ff2c78297c5745968b36d72475bf3539, State: Running, Role: LEADER
I20260812 06:17:02.474103 18593 consensus_queue.cc:237] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [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: "ff2c78297c5745968b36d72475bf3539" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 45529 } }
I20260812 06:17:02.475312 18331 catalog_manager.cc:5719] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 reported cstate change: term changed from 0 to 1, leader changed from <none> to ff2c78297c5745968b36d72475bf3539 (127.17.132.1). New cstate: current_term: 1 leader_uuid: "ff2c78297c5745968b36d72475bf3539" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ff2c78297c5745968b36d72475bf3539" member_type: VOTER last_known_addr { host: "127.17.132.1" port: 45529 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:02.532737 17936 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.018s	sys 0.004s
I20260812 06:17:02.691257 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3): perf score=20.047128
I20260812 06:17:02.860687 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.169s	user 0.108s	sys 0.056s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":937,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43207,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:02.861630 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling LogGCOp(d559f96fedda4134989f367d7a5f8ce3): free 20743880 bytes of WAL
I20260812 06:17:02.861894 18463 log_reader.cc:385] T d559f96fedda4134989f367d7a5f8ce3: removed 2 log segments from log reader
I20260812 06:17:02.861953 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000001 (ops 1-6)
I20260812 06:17:02.862067 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000002 (ops 7-11)
I20260812 06:17:02.868031 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: LogGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:17:02.868420 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3): 20513813 bytes on disk
I20260812 06:17:02.868880 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:02.869308 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:02.884986 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.885413 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:03.040154 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.155s	user 0.095s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":599,"lbm_read_time_us":10451,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25160,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":327,"threads_started":5,"update_count":2000}
I20260812 06:17:03.040802 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=14.095187
I20260812 06:17:03.106573 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.066s	user 0.033s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27067,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.107182 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:03.118237 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.118777 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:03.300014 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.181s	user 0.103s	sys 0.076s 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":198,"lbm_read_time_us":15352,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28754,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:03.300578 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=11.118625
I20260812 06:17:03.334954 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.034s	user 0.015s	sys 0.018s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14880,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:03.335693 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:03.352906 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6174,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.353691 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:03.483736 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.130s	user 0.083s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":428,"lbm_read_time_us":7912,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24239,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.484333 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=11.118625
I20260812 06:17:03.526741 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.042s	user 0.030s	sys 0.011s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":18699,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:03.527248 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:03.537766 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3545,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.538221 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:03.662357 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.124s	user 0.088s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":192,"lbm_read_time_us":9504,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23214,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36096,"update_count":2000}
I20260812 06:17:03.662921 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=10.126437
I20260812 06:17:03.701880 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.039s	user 0.015s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18900,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:03.702459 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:03.712553 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.010s	user 0.004s	sys 0.004s 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:17:03.713093 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:03.849416 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.136s	user 0.108s	sys 0.028s 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":943,"lbm_read_time_us":10494,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26006,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:17:03.850162 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=10.126437
I20260812 06:17:03.900674 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.050s	user 0.025s	sys 0.022s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16854,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:03.901283 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:03.911979 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.912433 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:04.065936 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.153s	user 0.106s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":11038,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24306,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:17:04.067022 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=11.118625
I20260812 06:17:04.098572 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.031s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12512611,"delete_count":0,"lbm_write_time_us":13777,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1525}
I20260812 06:17:04.099017 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:04.110950 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4101,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:04.111378 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:04.139689 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1209,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1351,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:04.140277 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling LogGCOp(d559f96fedda4134989f367d7a5f8ce3): free 124710298 bytes of WAL
I20260812 06:17:04.140501 18463 log_reader.cc:385] T d559f96fedda4134989f367d7a5f8ce3: removed 12 log segments from log reader
I20260812 06:17:04.140544 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000003 (ops 12-16)
I20260812 06:17:04.140573 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000004 (ops 17-21)
I20260812 06:17:04.140638 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000005 (ops 22-26)
I20260812 06:17:04.140683 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000006 (ops 27-31)
I20260812 06:17:04.140730 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000007 (ops 32-36)
I20260812 06:17:04.140785 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000008 (ops 37-41)
I20260812 06:17:04.140823 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000009 (ops 42-46)
I20260812 06:17:04.140861 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000010 (ops 47-51)
I20260812 06:17:04.140899 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000011 (ops 52-56)
I20260812 06:17:04.140937 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000012 (ops 57-61)
I20260812 06:17:04.140980 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000013 (ops 62-66)
I20260812 06:17:04.141017 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000014 (ops 67-71)
I20260812 06:17:04.168370 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: LogGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:04.168733 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=6.157687
I20260812 06:17:04.196684 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {"bytes_written":7712788,"delete_count":0,"lbm_write_time_us":8140,"lbm_writes_lt_1ms":191,"reinsert_count":0,"update_count":940}
I20260812 06:17:04.197229 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:04.396883 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.199s	user 0.130s	sys 0.065s Metrics: {"cfile_cache_miss":621,"cfile_cache_miss_bytes":28425922,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":6721,"lbm_read_time_us":14013,"lbm_reads_lt_1ms":653,"lbm_write_time_us":31552,"lbm_writes_lt_1ms":631,"mutex_wait_us":1973,"peak_mem_usage":74009668,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":104,"threads_started":1,"update_count":2940}
I20260812 06:17:04.398269 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=15.087375
I20260812 06:17:04.457392 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.059s	user 0.030s	sys 0.022s Metrics: {"bytes_written":17312440,"delete_count":0,"lbm_write_time_us":21388,"lbm_writes_lt_1ms":425,"reinsert_count":0,"update_count":2110}
I20260812 06:17:04.458061 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=4.173312
I20260812 06:17:04.474475 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":5456461,"delete_count":0,"lbm_write_time_us":6706,"lbm_writes_lt_1ms":136,"reinsert_count":0,"update_count":665}
I20260812 06:17:04.474962 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.196750
I20260812 06:17:04.485278 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":2338579,"delete_count":0,"lbm_write_time_us":3338,"lbm_writes_lt_1ms":60,"reinsert_count":0,"update_count":285}
I20260812 06:17:04.485786 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3): 462 bytes on disk
I20260812 06:17:04.486177 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:04.486613 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:04.706240 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.219s	user 0.138s	sys 0.079s Metrics: {"cfile_cache_miss":645,"cfile_cache_miss_bytes":29410469,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":329,"lbm_read_time_us":15362,"lbm_reads_lt_1ms":685,"lbm_write_time_us":36221,"lbm_writes_lt_1ms":655,"mutex_wait_us":68,"peak_mem_usage":77075276,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3060}
I20260812 06:17:04.706887 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=16.079562
I20260812 06:17:04.751502 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.044s	user 0.023s	sys 0.020s Metrics: {"bytes_written":17640627,"delete_count":0,"lbm_write_time_us":19500,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2150}
I20260812 06:17:04.752063 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.196750
I20260812 06:17:04.773399 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.021s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3613,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:17:04.774003 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:04.785251 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.785727 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:05.003372 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.217s	user 0.149s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918186,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":257,"lbm_read_time_us":13783,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35106,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":3000}
I20260812 06:17:05.004330 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=18.063937
I20260812 06:17:05.084920 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.080s	user 0.039s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":32655,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.085423 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:05.096735 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.097425 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:05.316962 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.219s	user 0.122s	sys 0.089s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":503,"lbm_read_time_us":13907,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37391,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20352,"update_count":3000}
I20260812 06:17:05.317757 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=18.063937
I20260812 06:17:05.385082 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.067s	user 0.031s	sys 0.028s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":28347,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.385665 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:05.397672 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.398142 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:05.607708 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.209s	user 0.129s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":414,"lbm_read_time_us":12986,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35874,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:17:05.608472 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=18.063937
I20260812 06:17:05.673357 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.065s	user 0.024s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24120,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:05.673915 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:05.685258 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:05.685757 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:05.713760 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.028s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1253,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1936,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:05.714380 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling LogGCOp(d559f96fedda4134989f367d7a5f8ce3): free 132571361 bytes of WAL
I20260812 06:17:05.714602 18463 log_reader.cc:385] T d559f96fedda4134989f367d7a5f8ce3: removed 13 log segments from log reader
I20260812 06:17:05.714664 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000015 (ops 72-76)
I20260812 06:17:05.714715 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000016 (ops 77-81)
I20260812 06:17:05.714771 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000017 (ops 82-86)
I20260812 06:17:05.714813 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000018 (ops 87-91)
I20260812 06:17:05.714850 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000019 (ops 92-96)
I20260812 06:17:05.714890 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000020 (ops 97-101)
I20260812 06:17:05.714928 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000021 (ops 102-106)
I20260812 06:17:05.714975 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000022 (ops 107-111)
I20260812 06:17:05.715013 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000023 (ops 112-116)
I20260812 06:17:05.715052 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000024 (ops 117-120)
I20260812 06:17:05.715090 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000025 (ops 121-125)
I20260812 06:17:05.715128 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000026 (ops 126-130)
I20260812 06:17:05.715166 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000027 (ops 131-134)
I20260812 06:17:05.745867 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: LogGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:05.746274 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3): 493 bytes on disk
I20260812 06:17:05.746798 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:05.747443 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=5.165500
I20260812 06:17:05.775465 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.028s	user 0.009s	sys 0.017s Metrics: {"bytes_written":6892307,"delete_count":0,"lbm_write_time_us":11484,"lbm_writes_lt_1ms":171,"reinsert_count":0,"update_count":840}
I20260812 06:17:05.776301 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:05.783591 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.007s	user 0.002s	sys 0.004s Metrics: {"bytes_written":1312952,"delete_count":0,"lbm_write_time_us":2092,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:17:05.784010 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:06.044488 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.260s	user 0.163s	sys 0.096s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123095,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":220,"lbm_read_time_us":21895,"lbm_reads_lt_1ms":874,"lbm_write_time_us":44944,"lbm_writes_lt_1ms":843,"mutex_wait_us":42,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":137,"threads_started":1,"update_count":4000}
I20260812 06:17:06.047273 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=19.056125
I20260812 06:17:06.120858 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.073s	user 0.037s	sys 0.031s Metrics: {"bytes_written":20922555,"delete_count":0,"lbm_write_time_us":32123,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:17:06.121318 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:06.133059 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.133488 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:06.147403 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5325,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:06.147866 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:06.337432 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.189s	user 0.149s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020614,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":77,"lbm_read_time_us":14090,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41149,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3500}
I20260812 06:17:06.338819 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=14.095187
I20260812 06:17:06.384042 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.045s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19966,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.384639 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:06.404614 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.020s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6024,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.405222 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:06.577039 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.172s	user 0.124s	sys 0.032s 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":143,"lbm_read_time_us":11641,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32469,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:17:06.578258 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=14.095187
I20260812 06:17:06.639578 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.061s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23326,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.640120 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:06.653321 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.653914 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:06.824698 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.171s	user 0.106s	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":1306,"lbm_read_time_us":10880,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26689,"lbm_writes_lt_1ms":543,"mutex_wait_us":467,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:06.825685 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=14.095187
I20260812 06:17:06.884061 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.058s	user 0.031s	sys 0.021s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":24672,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:06.884722 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:07.044521 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.160s	user 0.110s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713149,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":565,"lbm_read_time_us":10402,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25267,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2000}
I20260812 06:17:07.045275 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=14.095187
I20260812 06:17:07.103328 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.058s	user 0.045s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22272,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.103935 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:07.116451 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.117043 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:07.163234 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushMRSOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.046s	user 0.044s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":339,"dirs.run_wall_time_us":1569,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2380,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:07.164093 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling LogGCOp(d559f96fedda4134989f367d7a5f8ce3): free 112239561 bytes of WAL
I20260812 06:17:07.164343 18463 log_reader.cc:385] T d559f96fedda4134989f367d7a5f8ce3: removed 11 log segments from log reader
I20260812 06:17:07.164404 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000028 (ops 135-139)
I20260812 06:17:07.164458 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000029 (ops 140-144)
I20260812 06:17:07.164495 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000030 (ops 145-149)
I20260812 06:17:07.164520 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000031 (ops 150-154)
I20260812 06:17:07.164564 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000032 (ops 155-158)
I20260812 06:17:07.164611 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000033 (ops 159-163)
I20260812 06:17:07.164652 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000034 (ops 164-168)
I20260812 06:17:07.164705 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000035 (ops 169-173)
I20260812 06:17:07.164752 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000036 (ops 174-178)
I20260812 06:17:07.164788 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000037 (ops 179-183)
I20260812 06:17:07.164827 18463 log.cc:1079] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: Deleting log segment in path: /tmp/dist-test-taskpGtKMf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515416625390-17936-0/minicluster-data/ts-0-root/wals/d559f96fedda4134989f367d7a5f8ce3/wal-000000038 (ops 184-188)
I20260812 06:17:07.192595 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: LogGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.028s	user 0.001s	sys 0.024s Metrics: {}
I20260812 06:17:07.193089 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3): 447 bytes on disk
I20260812 06:17:07.193679 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: UndoDeltaBlockGCOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:07.194365 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:07.221916 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.027s	user 0.017s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":8293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.222725 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=2.188937
I20260812 06:17:07.235419 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:07.236152 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3): perf score=1.000000
I20260812 06:17:07.420562 17936 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.888s	user 1.769s	sys 0.226s
I20260812 06:17:07.474809 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: MajorDeltaCompactionOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.238s	user 0.167s	sys 0.070s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020744,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17195,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41763,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3500}
I20260812 06:17:07.475538 18565 maintenance_manager.cc:419] P ff2c78297c5745968b36d72475bf3539: Scheduling FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3): perf score=14.095187
I20260812 06:17:07.526423 17936 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.105s	user 0.002s	sys 0.000s
I20260812 06:17:07.526968 17936 tablet_server.cc:179] TabletServer@127.17.132.1:0 shutting down...
I20260812 06:17:07.561568 18463 maintenance_manager.cc:643] P ff2c78297c5745968b36d72475bf3539: FlushDeltaMemStoresOp(d559f96fedda4134989f367d7a5f8ce3) complete. Timing: real 0.086s	user 0.020s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:07.562245 17936 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:07.562525 17936 tablet_replica.cc:333] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539: stopping tablet replica
I20260812 06:17:07.562670 17936 raft_consensus.cc:2243] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.562850 17936 raft_consensus.cc:2272] T d559f96fedda4134989f367d7a5f8ce3 P ff2c78297c5745968b36d72475bf3539 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.576536 17936 tablet_server.cc:196] TabletServer@127.17.132.1:0 shutdown complete.
I20260812 06:17:07.586678 17936 master.cc:562] Master@127.17.132.62:40543 shutting down...
I20260812 06:17:07.590675 17936 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:07.590881 17936 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:07.590968 17936 tablet_replica.cc:333] T 00000000000000000000000000000000 P ec2ca7503e3b4c15a4f13d78703191e1: stopping tablet replica
I20260812 06:17:07.603392 17936 master.cc:584] Master@127.17.132.62:40543 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5362 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11066 ms total)

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