[==========] 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:19:58.411091 13214 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.231.190:44405
I20260812 06:19:58.412098 13214 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:19:58.412642 13214 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.418375 13229 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.418488 13214 server_base.cc:1061] running on GCE node
W20260812 06:19:58.418483 13221 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.418352 13224 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.419030 13214 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.419128 13214 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.419170 13214 hybrid_clock.cc:648] HybridClock initialized: now 1786515598419167 us; error 0 us; skew 500 ppm
I20260812 06:19:58.420722 13214 webserver.cc:533] Webserver started at http://127.12.231.190:41187/ using document root <none> and password file <none>
I20260812 06:19:58.421207 13214 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.421269 13214 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.421484 13214 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.423074 13214 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/master-0-root/instance:
uuid: "93af905ecaab40f7afe795141d7e29aa"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-cvwc"
I20260812 06:19:58.426256 13214 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:58.428081 13238 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.428992 13214 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:58.429093 13214 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/master-0-root
uuid: "93af905ecaab40f7afe795141d7e29aa"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-cvwc"
I20260812 06:19:58.429174 13214 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.448652 13214 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.449210 13214 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:19:58.449355 13214 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.456122 13318 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.231.190:44405 every 8 connection(s)
I20260812 06:19:58.456125 13214 rpc_server.cc:307] RPC server started. Bound to: 127.12.231.190:44405
I20260812 06:19:58.458158 13320 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.463168 13320 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: Bootstrap starting.
I20260812 06:19:58.465276 13320 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.466128 13320 log.cc:826] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:58.467588 13320 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: No bootstrap required, opened a new log
I20260812 06:19:58.470149 13320 raft_consensus.cc:359] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93af905ecaab40f7afe795141d7e29aa" member_type: VOTER }
I20260812 06:19:58.470297 13320 raft_consensus.cc:385] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.470356 13320 raft_consensus.cc:740] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 93af905ecaab40f7afe795141d7e29aa, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.470847 13320 consensus_queue.cc:260] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [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: "93af905ecaab40f7afe795141d7e29aa" member_type: VOTER }
I20260812 06:19:58.470969 13320 raft_consensus.cc:399] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.471012 13320 raft_consensus.cc:493] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.471095 13320 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.471767 13320 raft_consensus.cc:515] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93af905ecaab40f7afe795141d7e29aa" member_type: VOTER }
I20260812 06:19:58.472117 13320 leader_election.cc:304] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [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: 93af905ecaab40f7afe795141d7e29aa; no voters: 
I20260812 06:19:58.472379 13320 leader_election.cc:290] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.472477 13324 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.472685 13324 raft_consensus.cc:697] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 1 LEADER]: Becoming Leader. State: Replica: 93af905ecaab40f7afe795141d7e29aa, State: Running, Role: LEADER
I20260812 06:19:58.473062 13324 consensus_queue.cc:237] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [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: "93af905ecaab40f7afe795141d7e29aa" member_type: VOTER }
I20260812 06:19:58.473206 13320 sys_catalog.cc:565] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:58.474793 13326 sys_catalog.cc:455] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [sys.catalog]: SysCatalogTable state changed. Reason: New leader 93af905ecaab40f7afe795141d7e29aa. Latest consensus state: current_term: 1 leader_uuid: "93af905ecaab40f7afe795141d7e29aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93af905ecaab40f7afe795141d7e29aa" member_type: VOTER } }
I20260812 06:19:58.474784 13325 sys_catalog.cc:455] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "93af905ecaab40f7afe795141d7e29aa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "93af905ecaab40f7afe795141d7e29aa" member_type: VOTER } }
I20260812 06:19:58.474911 13326 sys_catalog.cc:458] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.474911 13325 sys_catalog.cc:458] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.475229 13214 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:58.476935 13349 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:58.476996 13349 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:58.477063 13348 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:58.477839 13348 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:58.482163 13348 catalog_manager.cc:1383] Generated new cluster ID: 714d2ccf49d5490d8780b76a35c1688e
I20260812 06:19:58.482220 13348 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:58.489792 13348 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:58.490798 13348 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:58.496716 13348 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: Generated new TSK 0
I20260812 06:19:58.497304 13348 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:58.507491 13214 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.509801 13357 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:19:58.509862 13360 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.509959 13356 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:19:58.510391 13214 server_base.cc:1061] running on GCE node
I20260812 06:19:58.510564 13214 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.510602 13214 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.510617 13214 hybrid_clock.cc:648] HybridClock initialized: now 1786515598510616 us; error 0 us; skew 500 ppm
I20260812 06:19:58.511447 13214 webserver.cc:533] Webserver started at http://127.12.231.129:36097/ using document root <none> and password file <none>
I20260812 06:19:58.511602 13214 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.511650 13214 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.511723 13214 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.512068 13214 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/instance:
uuid: "6a85e4f611fc46cb8e03ee70584dfdf4"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-cvwc"
I20260812 06:19:58.513466 13214 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:58.514426 13367 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.514678 13214 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:58.514743 13214 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root
uuid: "6a85e4f611fc46cb8e03ee70584dfdf4"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-cvwc"
I20260812 06:19:58.514809 13214 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.539760 13214 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.540184 13214 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.540649 13214 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:58.541481 13214 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:58.541532 13214 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.541577 13214 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:58.541607 13214 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.547607 13214 rpc_server.cc:307] RPC server started. Bound to: 127.12.231.129:38179
I20260812 06:19:58.547652 13469 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.231.129:38179 every 8 connection(s)
I20260812 06:19:58.557693 13470 heartbeater.cc:344] Connected to a master server at 127.12.231.190:44405
I20260812 06:19:58.557947 13470 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:58.558375 13470 heartbeater.cc:507] Master 127.12.231.190:44405 requested a full tablet report, sending...
I20260812 06:19:58.559719 13261 ts_manager.cc:194] Registered new tserver with Master: 6a85e4f611fc46cb8e03ee70584dfdf4 (127.12.231.129:38179)
I20260812 06:19:58.560415 13214 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012219834s
I20260812 06:19:58.561043 13261 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36806
I20260812 06:19:58.569286 13261 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36822:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:58.582345 13408 tablet_service.cc:1511] Processing CreateTablet for tablet 7a62b41ce2bf4a27ac406b1dcc219e41 (DEFAULT_TABLE table=heavy-update-compaction-test [id=858fa918bab44294b53174b7616cce71]), partition=
I20260812 06:19:58.582764 13408 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7a62b41ce2bf4a27ac406b1dcc219e41. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.584970 13494 tablet_bootstrap.cc:492] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Bootstrap starting.
I20260812 06:19:58.585701 13494 tablet_bootstrap.cc:654] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.586870 13494 tablet_bootstrap.cc:492] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: No bootstrap required, opened a new log
I20260812 06:19:58.586952 13494 ts_tablet_manager.cc:1403] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:58.587333 13494 raft_consensus.cc:359] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a85e4f611fc46cb8e03ee70584dfdf4" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38179 } }
I20260812 06:19:58.587430 13494 raft_consensus.cc:385] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.587477 13494 raft_consensus.cc:740] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6a85e4f611fc46cb8e03ee70584dfdf4, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.587603 13494 consensus_queue.cc:260] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [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: "6a85e4f611fc46cb8e03ee70584dfdf4" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38179 } }
I20260812 06:19:58.587671 13494 raft_consensus.cc:399] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.587713 13494 raft_consensus.cc:493] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.587759 13494 raft_consensus.cc:3060] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.588423 13494 raft_consensus.cc:515] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a85e4f611fc46cb8e03ee70584dfdf4" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38179 } }
I20260812 06:19:58.588557 13494 leader_election.cc:304] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [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: 6a85e4f611fc46cb8e03ee70584dfdf4; no voters: 
I20260812 06:19:58.588727 13494 leader_election.cc:290] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.588828 13498 raft_consensus.cc:2804] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.589039 13494 ts_tablet_manager.cc:1434] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:58.589066 13498 raft_consensus.cc:697] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 1 LEADER]: Becoming Leader. State: Replica: 6a85e4f611fc46cb8e03ee70584dfdf4, State: Running, Role: LEADER
I20260812 06:19:58.589224 13498 consensus_queue.cc:237] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [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: "6a85e4f611fc46cb8e03ee70584dfdf4" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38179 } }
I20260812 06:19:58.589270 13470 heartbeater.cc:499] Master 127.12.231.190:44405 was elected leader, sending a full tablet report...
I20260812 06:19:58.591557 13261 catalog_manager.cc:5719] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6a85e4f611fc46cb8e03ee70584dfdf4 (127.12.231.129). New cstate: current_term: 1 leader_uuid: "6a85e4f611fc46cb8e03ee70584dfdf4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6a85e4f611fc46cb8e03ee70584dfdf4" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38179 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:58.653630 13214 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.022s	sys 0.005s
I20260812 06:19:58.798681 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=19.054940
I20260812 06:19:58.946204 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.147s	user 0.108s	sys 0.037s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":196,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":855,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37086,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":87,"threads_started":1,"update_count":1500}
I20260812 06:19:58.947264 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): free 20743880 bytes of WAL
I20260812 06:19:58.947561 13372 log_reader.cc:385] T 7a62b41ce2bf4a27ac406b1dcc219e41: removed 2 log segments from log reader
I20260812 06:19:58.947638 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000001 (ops 1-6)
I20260812 06:19:58.947693 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000002 (ops 7-11)
I20260812 06:19:58.951988 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:58.952345 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:19:58.967895 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.968389 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:19:59.109836 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.141s	user 0.085s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":713,"lbm_read_time_us":8281,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23379,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":299,"threads_started":5,"update_count":2000}
I20260812 06:19:59.110299 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:19:59.146638 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.036s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13321,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.149731 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:19:59.162561 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.162955 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:19:59.274962 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.112s	user 0.098s	sys 0.013s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":7589,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21009,"lbm_writes_lt_1ms":443,"mutex_wait_us":10,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.275408 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:19:59.309170 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.034s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13577,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.309610 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:19:59.319427 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.319912 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:19:59.442953 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.123s	user 0.109s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":149,"lbm_read_time_us":9012,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22848,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:19:59.443395 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): 16411392 bytes on disk
I20260812 06:19:59.443838 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.444235 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:19:59.488214 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.044s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16272,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.488680 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:19:59.498162 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.498558 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:19:59.627157 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.128s	user 0.110s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":917,"lbm_read_time_us":8914,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20624,"lbm_writes_lt_1ms":443,"mutex_wait_us":246,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.627648 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:19:59.656049 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.028s	user 0.016s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11576,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.658056 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:19:59.753090 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.095s	user 0.062s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":117,"lbm_read_time_us":6058,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17179,"lbm_writes_lt_1ms":343,"mutex_wait_us":20,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.753587 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:19:59.784106 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.030s	user 0.012s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12471,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.784584 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:19:59.887079 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.102s	user 0.065s	sys 0.035s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":573,"lbm_read_time_us":6815,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18642,"lbm_writes_lt_1ms":343,"mutex_wait_us":35,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.887593 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:19:59.918218 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.030s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11608,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.918700 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:00.015415 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.097s	user 0.080s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":916,"lbm_read_time_us":5446,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19036,"lbm_writes_lt_1ms":343,"mutex_wait_us":272,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":1500}
I20260812 06:20:00.015887 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:20:00.061360 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.045s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15865,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:00.061933 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:00.071192 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.071571 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:00.098661 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.027s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1305,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1445,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:00.099385 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): free 112239310 bytes of WAL
I20260812 06:20:00.099582 13372 log_reader.cc:385] T 7a62b41ce2bf4a27ac406b1dcc219e41: removed 11 log segments from log reader
I20260812 06:20:00.099625 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000003 (ops 12-16)
I20260812 06:20:00.099653 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000004 (ops 17-21)
I20260812 06:20:00.099684 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000005 (ops 22-26)
I20260812 06:20:00.099716 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000006 (ops 27-31)
I20260812 06:20:00.099746 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000007 (ops 32-36)
I20260812 06:20:00.099779 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000008 (ops 37-40)
I20260812 06:20:00.099810 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000009 (ops 41-45)
I20260812 06:20:00.099841 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000010 (ops 46-50)
I20260812 06:20:00.099874 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000011 (ops 51-55)
I20260812 06:20:00.099903 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000012 (ops 56-60)
I20260812 06:20:00.099934 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000013 (ops 61-65)
I20260812 06:20:00.118073 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.019s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:20:00.118499 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=3.181125
I20260812 06:20:00.134585 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.016s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3837,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:00.134994 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): 462 bytes on disk
I20260812 06:20:00.135367 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.135843 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:00.144446 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.008s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3036,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.144807 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:00.313800 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.169s	user 0.126s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":219,"lbm_read_time_us":12334,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29639,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:20:00.314255 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:00.363994 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.050s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17800,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.364512 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:00.373912 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.374413 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:00.528911 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.154s	user 0.115s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":845,"lbm_read_time_us":10772,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26814,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:00.529452 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:00.576928 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.047s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19075,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.577353 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:00.586726 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.587255 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:00.758349 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.171s	user 0.132s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":11879,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25305,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:00.758842 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:00.813429 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.054s	user 0.025s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18590,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.813962 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:00.824105 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3625,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.824599 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:01.002004 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.177s	user 0.102s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1285,"lbm_read_time_us":12252,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31868,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.002490 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:01.053128 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.050s	user 0.012s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16871,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.053745 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:01.064368 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.064937 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:01.227082 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.162s	user 0.097s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":561,"lbm_read_time_us":10444,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24961,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:01.227583 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:01.280344 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.053s	user 0.027s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20348,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.280903 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:01.290611 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.291105 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:01.443008 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.152s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":853,"lbm_read_time_us":11508,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26159,"lbm_writes_lt_1ms":543,"mutex_wait_us":238,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:20:01.443578 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=10.126437
I20260812 06:20:01.485185 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.041s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.485653 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:01.495522 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.496034 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:01.528473 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.032s	user 0.023s	sys 0.006s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":39,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1352,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1310,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":1408}
I20260812 06:20:01.529254 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): free 133024368 bytes of WAL
I20260812 06:20:01.529486 13372 log_reader.cc:385] T 7a62b41ce2bf4a27ac406b1dcc219e41: removed 13 log segments from log reader
I20260812 06:20:01.529546 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000014 (ops 66-70)
I20260812 06:20:01.529592 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000015 (ops 71-75)
I20260812 06:20:01.529623 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000016 (ops 76-80)
I20260812 06:20:01.529644 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000017 (ops 81-85)
I20260812 06:20:01.529675 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000018 (ops 86-90)
I20260812 06:20:01.529707 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000019 (ops 91-94)
I20260812 06:20:01.529759 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000020 (ops 95-99)
I20260812 06:20:01.529788 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000021 (ops 100-104)
I20260812 06:20:01.529816 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000022 (ops 105-109)
I20260812 06:20:01.529846 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000023 (ops 110-114)
I20260812 06:20:01.529879 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000024 (ops 115-119)
I20260812 06:20:01.529908 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000025 (ops 120-124)
I20260812 06:20:01.529935 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000026 (ops 125-129)
I20260812 06:20:01.556663 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:01.557065 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): 482 bytes on disk
I20260812 06:20:01.557510 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.558195 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:01.574082 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.016s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:20:01.574524 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:01.749622 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.175s	user 0.112s	sys 0.061s Metrics: {"cfile_cache_miss":535,"cfile_cache_miss_bytes":24856857,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":856,"lbm_read_time_us":12124,"lbm_reads_lt_1ms":567,"lbm_write_time_us":30481,"lbm_writes_lt_1ms":545,"mutex_wait_us":439,"peak_mem_usage":63197970,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":73,"threads_started":1,"update_count":2510}
I20260812 06:20:01.750146 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=15.087375
I20260812 06:20:01.802317 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.052s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16738097,"delete_count":0,"lbm_write_time_us":21682,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":410,"reinsert_count":0,"update_count":2040}
I20260812 06:20:01.802788 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:01.818490 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.016s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4225734,"delete_count":0,"lbm_write_time_us":3596,"lbm_writes_lt_1ms":106,"mutex_wait_us":47,"reinsert_count":0,"update_count":515}
I20260812 06:20:01.818890 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:01.827602 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3272,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:20:01.827977 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:02.006692 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.179s	user 0.125s	sys 0.050s Metrics: {"cfile_cache_miss":631,"cfile_cache_miss_bytes":28795161,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":941,"lbm_read_time_us":13977,"lbm_reads_lt_1ms":671,"lbm_write_time_us":28769,"lbm_writes_lt_1ms":641,"mutex_wait_us":1,"peak_mem_usage":74420018,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2990}
I20260812 06:20:02.007164 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:02.059564 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.052s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16704,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.060111 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:02.074918 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5500,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.075430 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:02.241858 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.166s	user 0.116s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":538,"lbm_read_time_us":11421,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28027,"lbm_writes_lt_1ms":543,"mutex_wait_us":242,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.244426 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=11.118625
I20260812 06:20:02.271306 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.027s	user 0.021s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11340,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:02.271792 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:02.288640 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.017s	user 0.000s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4989,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.289113 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:02.452586 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.163s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":8769,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23409,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:02.453173 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:02.507555 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.054s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.508035 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:02.518904 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.519338 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:02.655521 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.136s	user 0.100s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":964,"lbm_read_time_us":8789,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29200,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.656008 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=11.118625
I20260812 06:20:02.706914 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.051s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":23036,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1550}
I20260812 06:20:02.707417 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:02.723542 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.723941 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:02.732596 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3116,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.732981 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:02.878239 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.145s	user 0.104s	sys 0.038s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":612,"lbm_read_time_us":8498,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28197,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":484352,"update_count":2500}
I20260812 06:20:02.879472 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=12.110812
I20260812 06:20:02.911085 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":13620266,"delete_count":0,"lbm_write_time_us":13262,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:20:02.911761 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.196750
I20260812 06:20:02.921785 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3422,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:20:02.922227 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:02.952015 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushMRSOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1281,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1266,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:02.952666 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): free 120553601 bytes of WAL
I20260812 06:20:02.952880 13372 log_reader.cc:385] T 7a62b41ce2bf4a27ac406b1dcc219e41: removed 12 log segments from log reader
I20260812 06:20:02.952927 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000027 (ops 130-134)
I20260812 06:20:02.952960 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000028 (ops 135-139)
I20260812 06:20:02.952983 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000029 (ops 140-144)
I20260812 06:20:02.953014 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000030 (ops 145-149)
I20260812 06:20:02.953045 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000031 (ops 150-154)
I20260812 06:20:02.953078 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000032 (ops 155-158)
I20260812 06:20:02.953109 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000033 (ops 159-163)
I20260812 06:20:02.953140 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000034 (ops 164-168)
I20260812 06:20:02.953172 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000035 (ops 169-173)
I20260812 06:20:02.953204 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000036 (ops 174-178)
I20260812 06:20:02.953235 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000037 (ops 179-182)
I20260812 06:20:02.953269 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000038 (ops 183-187)
I20260812 06:20:02.972968 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:02.973438 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=3.181125
I20260812 06:20:02.989806 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.016s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6557,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:02.990203 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): free 12018011 bytes of WAL
I20260812 06:20:02.990386 13372 log_reader.cc:385] T 7a62b41ce2bf4a27ac406b1dcc219e41: removed 1 log segments from log reader
I20260812 06:20:02.990429 13372 log.cc:1079] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/7a62b41ce2bf4a27ac406b1dcc219e41/wal-000000039 (ops 188-192)
I20260812 06:20:02.992148 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: LogGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:02.992426 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=2.188937
I20260812 06:20:03.002413 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3154,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.002897 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:03.177346 13214 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.524s	user 1.669s	sys 0.131s
I20260812 06:20:03.187601 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.185s	user 0.123s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877298,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13384,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33042,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:20:03.188030 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41): 470 bytes on disk
I20260812 06:20:03.188370 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: UndoDeltaBlockGCOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.188868 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=14.095187
I20260812 06:20:03.219179 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: FlushDeltaMemStoresOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.030s	user 0.022s	sys 0.007s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":13889,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:20:03.219619 13475 maintenance_manager.cc:419] P 6a85e4f611fc46cb8e03ee70584dfdf4: Scheduling MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41): perf score=1.000000
I20260812 06:20:03.254776 13214 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.077s	user 0.003s	sys 0.000s
I20260812 06:20:03.255367 13214 tablet_server.cc:179] TabletServer@127.12.231.129:0 shutting down...
I20260812 06:20:03.326792 13372 maintenance_manager.cc:643] P 6a85e4f611fc46cb8e03ee70584dfdf4: MajorDeltaCompactionOp(7a62b41ce2bf4a27ac406b1dcc219e41) complete. Timing: real 0.107s	user 0.081s	sys 0.025s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":314,"lbm_read_time_us":8216,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21196,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:20:03.327489 13214 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:03.327896 13214 tablet_replica.cc:333] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4: stopping tablet replica
I20260812 06:20:03.328118 13214 raft_consensus.cc:2243] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.328349 13214 raft_consensus.cc:2272] T 7a62b41ce2bf4a27ac406b1dcc219e41 P 6a85e4f611fc46cb8e03ee70584dfdf4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.344035 13214 tablet_server.cc:196] TabletServer@127.12.231.129:0 shutdown complete.
I20260812 06:20:03.365453 13214 master.cc:562] Master@127.12.231.190:44405 shutting down...
I20260812 06:20:03.368546 13214 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.368695 13214 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.368748 13214 tablet_replica.cc:333] T 00000000000000000000000000000000 P 93af905ecaab40f7afe795141d7e29aa: stopping tablet replica
I20260812 06:20:03.380848 13214 master.cc:584] Master@127.12.231.190:44405 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5036 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:03.456777 13214 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.231.190:37075
I20260812 06:20:03.457216 13214 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:03.459393 13524 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.459399 13521 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.459499 13520 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:03.459543 13214 server_base.cc:1061] running on GCE node
I20260812 06:20:03.459801 13214 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:03.459844 13214 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:03.459859 13214 hybrid_clock.cc:648] HybridClock initialized: now 1786515603459859 us; error 0 us; skew 500 ppm
I20260812 06:20:03.460613 13214 webserver.cc:533] Webserver started at http://127.12.231.190:39597/ using document root <none> and password file <none>
I20260812 06:20:03.460736 13214 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:03.460772 13214 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:03.460829 13214 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:03.461153 13214 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/master-0-root/instance:
uuid: "5092abf6458f41d29e605c6db636bf4d"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-cvwc"
I20260812 06:20:03.462610 13214 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:03.463495 13531 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.463737 13214 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:03.463805 13214 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/master-0-root
uuid: "5092abf6458f41d29e605c6db636bf4d"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-cvwc"
I20260812 06:20:03.463879 13214 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:03.478092 13214 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:03.478401 13214 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:03.482163 13214 rpc_server.cc:307] RPC server started. Bound to: 127.12.231.190:37075
I20260812 06:20:03.485574 13616 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.231.190:37075 every 8 connection(s)
I20260812 06:20:03.486080 13618 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:03.487802 13618 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d: Bootstrap starting.
I20260812 06:20:03.488559 13618 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:03.489435 13618 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d: No bootstrap required, opened a new log
I20260812 06:20:03.489845 13618 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5092abf6458f41d29e605c6db636bf4d" member_type: VOTER }
I20260812 06:20:03.489933 13618 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:03.489959 13618 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5092abf6458f41d29e605c6db636bf4d, State: Initialized, Role: FOLLOWER
I20260812 06:20:03.490074 13618 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [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: "5092abf6458f41d29e605c6db636bf4d" member_type: VOTER }
I20260812 06:20:03.490156 13618 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:03.490185 13618 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:03.490221 13618 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:03.490828 13618 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5092abf6458f41d29e605c6db636bf4d" member_type: VOTER }
I20260812 06:20:03.490940 13618 leader_election.cc:304] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [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: 5092abf6458f41d29e605c6db636bf4d; no voters: 
I20260812 06:20:03.491077 13618 leader_election.cc:290] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:03.491192 13623 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:03.491395 13623 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 1 LEADER]: Becoming Leader. State: Replica: 5092abf6458f41d29e605c6db636bf4d, State: Running, Role: LEADER
I20260812 06:20:03.491503 13618 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:03.491530 13623 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [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: "5092abf6458f41d29e605c6db636bf4d" member_type: VOTER }
I20260812 06:20:03.491943 13627 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5092abf6458f41d29e605c6db636bf4d. Latest consensus state: current_term: 1 leader_uuid: "5092abf6458f41d29e605c6db636bf4d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5092abf6458f41d29e605c6db636bf4d" member_type: VOTER } }
I20260812 06:20:03.492048 13627 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:03.491923 13626 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5092abf6458f41d29e605c6db636bf4d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5092abf6458f41d29e605c6db636bf4d" member_type: VOTER } }
I20260812 06:20:03.492144 13626 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:03.492538 13634 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:03.493184 13634 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:03.493371 13214 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:03.494832 13634 catalog_manager.cc:1383] Generated new cluster ID: b890daec38374d9b8c5b2f8485738dc1
I20260812 06:20:03.494877 13634 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:03.502028 13634 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:03.502523 13634 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:03.509580 13634 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d: Generated new TSK 0
I20260812 06:20:03.509739 13634 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:03.525465 13214 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:03.527381 13662 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.527509 13667 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.527522 13663 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:03.527500 13214 server_base.cc:1061] running on GCE node
I20260812 06:20:03.527828 13214 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:03.527869 13214 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:03.527884 13214 hybrid_clock.cc:648] HybridClock initialized: now 1786515603527883 us; error 0 us; skew 500 ppm
I20260812 06:20:03.528613 13214 webserver.cc:533] Webserver started at http://127.12.231.129:33229/ using document root <none> and password file <none>
I20260812 06:20:03.528734 13214 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:03.528774 13214 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:03.528831 13214 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:03.529151 13214 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/instance:
uuid: "53feb1c78d434a369ba10bd3cf1eaeaf"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-cvwc"
I20260812 06:20:03.530550 13214 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:03.531347 13678 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.531553 13214 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:03.531616 13214 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root
uuid: "53feb1c78d434a369ba10bd3cf1eaeaf"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-cvwc"
I20260812 06:20:03.531679 13214 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:03.541316 13214 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:03.541668 13214 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:03.541962 13214 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:03.542405 13214 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:03.542441 13214 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.542482 13214 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:03.542510 13214 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.546495 13214 rpc_server.cc:307] RPC server started. Bound to: 127.12.231.129:38201
I20260812 06:20:03.546540 13792 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.231.129:38201 every 8 connection(s)
I20260812 06:20:03.554260 13794 heartbeater.cc:344] Connected to a master server at 127.12.231.190:37075
I20260812 06:20:03.554353 13794 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:03.554580 13794 heartbeater.cc:507] Master 127.12.231.190:37075 requested a full tablet report, sending...
I20260812 06:20:03.555168 13561 ts_manager.cc:194] Registered new tserver with Master: 53feb1c78d434a369ba10bd3cf1eaeaf (127.12.231.129:38201)
I20260812 06:20:03.555675 13214 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008793735s
I20260812 06:20:03.555917 13561 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58522
I20260812 06:20:03.561707 13561 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58532:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:03.569440 13727 tablet_service.cc:1511] Processing CreateTablet for tablet b3786700633b47d79f9c8fac23ea98f2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=6f9d88866690414c8cf8e4ceee168fa4]), partition=
I20260812 06:20:03.569664 13727 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b3786700633b47d79f9c8fac23ea98f2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:03.571476 13819 tablet_bootstrap.cc:492] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Bootstrap starting.
I20260812 06:20:03.572294 13819 tablet_bootstrap.cc:654] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:03.573264 13819 tablet_bootstrap.cc:492] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: No bootstrap required, opened a new log
I20260812 06:20:03.573343 13819 ts_tablet_manager.cc:1403] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:03.573746 13819 raft_consensus.cc:359] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53feb1c78d434a369ba10bd3cf1eaeaf" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38201 } }
I20260812 06:20:03.573841 13819 raft_consensus.cc:385] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:03.573881 13819 raft_consensus.cc:740] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 53feb1c78d434a369ba10bd3cf1eaeaf, State: Initialized, Role: FOLLOWER
I20260812 06:20:03.574005 13819 consensus_queue.cc:260] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [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: "53feb1c78d434a369ba10bd3cf1eaeaf" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38201 } }
I20260812 06:20:03.574086 13819 raft_consensus.cc:399] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:03.574126 13819 raft_consensus.cc:493] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:03.574172 13819 raft_consensus.cc:3060] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:03.574843 13819 raft_consensus.cc:515] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53feb1c78d434a369ba10bd3cf1eaeaf" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38201 } }
I20260812 06:20:03.574968 13819 leader_election.cc:304] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [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: 53feb1c78d434a369ba10bd3cf1eaeaf; no voters: 
I20260812 06:20:03.575150 13819 leader_election.cc:290] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:03.575248 13822 raft_consensus.cc:2804] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:03.575402 13822 raft_consensus.cc:697] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 1 LEADER]: Becoming Leader. State: Replica: 53feb1c78d434a369ba10bd3cf1eaeaf, State: Running, Role: LEADER
I20260812 06:20:03.575448 13819 ts_tablet_manager.cc:1434] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:03.575528 13822 consensus_queue.cc:237] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [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: "53feb1c78d434a369ba10bd3cf1eaeaf" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38201 } }
I20260812 06:20:03.575606 13794 heartbeater.cc:499] Master 127.12.231.190:37075 was elected leader, sending a full tablet report...
I20260812 06:20:03.576694 13561 catalog_manager.cc:5719] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf reported cstate change: term changed from 0 to 1, leader changed from <none> to 53feb1c78d434a369ba10bd3cf1eaeaf (127.12.231.129). New cstate: current_term: 1 leader_uuid: "53feb1c78d434a369ba10bd3cf1eaeaf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "53feb1c78d434a369ba10bd3cf1eaeaf" member_type: VOTER last_known_addr { host: "127.12.231.129" port: 38201 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:03.629576 13214 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.019s	sys 0.002s
I20260812 06:20:03.797437 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2): perf score=23.023690
I20260812 06:20:03.945094 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.147s	user 0.112s	sys 0.032s Metrics: {"bytes_written":13292061,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":28,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":785,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40206,"lbm_writes_lt_1ms":881,"mutex_wait_us":799,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":10368,"update_count":1620}
I20260812 06:20:03.945775 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling LogGCOp(b3786700633b47d79f9c8fac23ea98f2): free 20743880 bytes of WAL
I20260812 06:20:03.945968 13686 log_reader.cc:385] T b3786700633b47d79f9c8fac23ea98f2: removed 2 log segments from log reader
I20260812 06:20:03.946049 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000001 (ops 1-6)
I20260812 06:20:03.946102 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000002 (ops 7-11)
I20260812 06:20:03.949744 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: LogGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:03.950093 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2): 20513813 bytes on disk
I20260812 06:20:03.950454 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.950851 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:03.969841 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.019s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3528309,"delete_count":0,"lbm_write_time_us":3296,"lbm_writes_lt_1ms":89,"reinsert_count":0,"update_count":430}
I20260812 06:20:03.970209 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:03.978551 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3099,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.978890 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:04.153553 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.174s	user 0.125s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815770,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":447,"lbm_read_time_us":10965,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28511,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":325,"threads_started":5,"update_count":2500}
I20260812 06:20:04.154034 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:04.205075 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.051s	user 0.018s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17761,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.205579 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:04.219565 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5184,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.220005 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:04.389426 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.169s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":625,"lbm_read_time_us":10847,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27418,"lbm_writes_lt_1ms":543,"mutex_wait_us":226,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:04.389923 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:04.449625 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.060s	user 0.024s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25076,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.450121 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:04.464741 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5584,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.465224 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:04.636986 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.172s	user 0.125s	sys 0.040s 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":222,"lbm_read_time_us":11867,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27359,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:20:04.637499 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:04.691910 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.054s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.692395 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:04.702154 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.702622 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:04.877593 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.175s	user 0.108s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":525,"lbm_read_time_us":10854,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26142,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:04.878068 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:04.929570 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.051s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22859,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.930090 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:04.947870 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.018s	user 0.000s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.950052 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:05.128423 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.178s	user 0.133s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":440,"lbm_read_time_us":12210,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28487,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:20:05.129432 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:05.174589 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.045s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19717,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.175230 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:05.190250 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.190828 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:05.235852 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.045s	user 0.026s	sys 0.002s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1224,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2004,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:05.236447 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling LogGCOp(b3786700633b47d79f9c8fac23ea98f2): free 124710249 bytes of WAL
I20260812 06:20:05.236689 13686 log_reader.cc:385] T b3786700633b47d79f9c8fac23ea98f2: removed 12 log segments from log reader
I20260812 06:20:05.236749 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000003 (ops 12-16)
I20260812 06:20:05.236791 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000004 (ops 17-21)
I20260812 06:20:05.236822 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000005 (ops 22-26)
I20260812 06:20:05.236853 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000006 (ops 27-31)
I20260812 06:20:05.236883 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000007 (ops 32-36)
I20260812 06:20:05.236912 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000008 (ops 37-41)
I20260812 06:20:05.236941 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000009 (ops 42-46)
I20260812 06:20:05.236970 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000010 (ops 47-51)
I20260812 06:20:05.236999 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000011 (ops 52-56)
I20260812 06:20:05.237027 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000012 (ops 57-61)
I20260812 06:20:05.237054 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000013 (ops 62-66)
I20260812 06:20:05.237083 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000014 (ops 67-71)
I20260812 06:20:05.255532 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: LogGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.019s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:05.255896 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=6.157687
I20260812 06:20:05.275434 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.019s	user 0.016s	sys 0.002s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":7663,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:05.276098 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2): 482 bytes on disk
I20260812 06:20:05.276590 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.277371 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:05.494014 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.217s	user 0.125s	sys 0.091s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020626,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":226,"lbm_read_time_us":13308,"lbm_reads_lt_1ms":765,"lbm_write_time_us":34404,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:20:05.494504 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=18.063937
I20260812 06:20:05.554123 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.059s	user 0.019s	sys 0.028s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":21115,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:05.554667 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:05.564944 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.565502 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:05.770328 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.205s	user 0.154s	sys 0.047s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":999,"lbm_read_time_us":13398,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36200,"lbm_writes_lt_1ms":643,"mutex_wait_us":301,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":3000}
I20260812 06:20:05.770967 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=15.087375
I20260812 06:20:05.816069 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.045s	user 0.019s	sys 0.021s Metrics: {"bytes_written":17476527,"delete_count":0,"lbm_write_time_us":18543,"lbm_writes_lt_1ms":429,"reinsert_count":0,"update_count":2130}
I20260812 06:20:05.816588 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:05.834964 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.018s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3446259,"delete_count":0,"lbm_write_time_us":3656,"lbm_writes_lt_1ms":87,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":420}
I20260812 06:20:05.835424 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:05.844074 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3182,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.844435 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:06.027068 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.182s	user 0.112s	sys 0.071s 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":111,"lbm_read_time_us":11573,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29369,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":3000}
I20260812 06:20:06.027833 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:06.073596 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.045s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19930,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.074110 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:06.093165 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.019s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.093672 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:06.262015 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.168s	user 0.128s	sys 0.040s 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":342,"lbm_read_time_us":11882,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27270,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:06.262707 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:06.307003 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.044s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17011,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.307615 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=3.181125
I20260812 06:20:06.322454 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:06.322844 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:06.331768 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3314,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.332172 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:06.517921 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.186s	user 0.109s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918200,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":899,"lbm_read_time_us":13256,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29083,"lbm_writes_lt_1ms":643,"mutex_wait_us":290,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":3000}
I20260812 06:20:06.518389 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:06.567040 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.048s	user 0.024s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20640,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.567507 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:06.602595 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.035s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1326,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1892,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:06.603210 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=3.181125
I20260812 06:20:06.616832 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.013s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":3891,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:06.617337 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling LogGCOp(b3786700633b47d79f9c8fac23ea98f2): free 120553443 bytes of WAL
I20260812 06:20:06.617565 13686 log_reader.cc:385] T b3786700633b47d79f9c8fac23ea98f2: removed 12 log segments from log reader
I20260812 06:20:06.617614 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000015 (ops 72-76)
I20260812 06:20:06.617653 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000016 (ops 77-80)
I20260812 06:20:06.617686 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000017 (ops 81-85)
I20260812 06:20:06.617736 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000018 (ops 86-90)
I20260812 06:20:06.617769 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000019 (ops 91-95)
I20260812 06:20:06.617794 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000020 (ops 96-100)
I20260812 06:20:06.617825 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000021 (ops 101-104)
I20260812 06:20:06.617851 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000022 (ops 105-109)
I20260812 06:20:06.617882 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000023 (ops 110-114)
I20260812 06:20:06.617913 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000024 (ops 115-119)
I20260812 06:20:06.617942 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000025 (ops 120-124)
I20260812 06:20:06.617973 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000026 (ops 125-129)
I20260812 06:20:06.639180 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: LogGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.022s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:20:06.639578 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2): 462 bytes on disk
I20260812 06:20:06.639995 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2) 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:20:06.640496 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:06.658490 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.018s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3408,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.659008 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:06.673676 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.674237 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:06.884837 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.210s	user 0.166s	sys 0.041s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":736,"lbm_read_time_us":15084,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33613,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11136,"thread_start_us":106,"threads_started":1,"update_count":3500}
I20260812 06:20:06.885298 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=18.063937
I20260812 06:20:06.932447 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.047s	user 0.037s	sys 0.007s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":20465,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:06.933077 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:06.949196 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.949620 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:07.119591 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.170s	user 0.127s	sys 0.037s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":351,"lbm_read_time_us":12415,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33439,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:20:07.120177 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:07.194029 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.074s	user 0.021s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":52977,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.194567 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:07.206199 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.206732 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:07.355679 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.149s	user 0.108s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":8581,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27513,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:07.356310 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=14.095187
I20260812 06:20:07.397572 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.041s	user 0.034s	sys 0.003s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18033,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.398072 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:07.532120 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.134s	user 0.086s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":823,"lbm_read_time_us":8644,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21040,"lbm_writes_lt_1ms":443,"mutex_wait_us":270,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:07.532799 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=10.126437
I20260812 06:20:07.561054 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":11837,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.561532 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:07.577450 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5895,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.577975 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:07.705030 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.127s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1573,"lbm_read_time_us":8123,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23417,"lbm_writes_lt_1ms":443,"mutex_wait_us":429,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:07.705541 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=10.126437
I20260812 06:20:07.735412 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.030s	user 0.026s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11285,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.735915 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:07.750896 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.751392 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:07.866902 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.115s	user 0.091s	sys 0.024s 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":787,"lbm_read_time_us":7422,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22369,"lbm_writes_lt_1ms":443,"mutex_wait_us":256,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:20:07.867378 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=10.126437
I20260812 06:20:07.909659 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.042s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.912000 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:07.923799 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4457,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.924285 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:07.951485 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushMRSOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.027s	user 0.018s	sys 0.007s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":167,"dirs.run_wall_time_us":1009,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1317,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:07.952126 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling LogGCOp(b3786700633b47d79f9c8fac23ea98f2): free 120553586 bytes of WAL
I20260812 06:20:07.952334 13686 log_reader.cc:385] T b3786700633b47d79f9c8fac23ea98f2: removed 12 log segments from log reader
I20260812 06:20:07.952381 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000027 (ops 130-134)
I20260812 06:20:07.952418 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000028 (ops 135-139)
I20260812 06:20:07.952490 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000029 (ops 140-144)
I20260812 06:20:07.952529 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000030 (ops 145-148)
I20260812 06:20:07.952548 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000031 (ops 149-153)
I20260812 06:20:07.952564 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000032 (ops 154-158)
I20260812 06:20:07.952594 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000033 (ops 159-163)
I20260812 06:20:07.952628 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000034 (ops 164-168)
I20260812 06:20:07.952661 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000035 (ops 169-172)
I20260812 06:20:07.952694 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000036 (ops 173-177)
I20260812 06:20:07.952726 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000037 (ops 178-182)
I20260812 06:20:07.952759 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000038 (ops 183-187)
I20260812 06:20:07.973752 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: LogGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.021s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:07.974184 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=3.181125
I20260812 06:20:07.987547 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":5005191,"delete_count":0,"lbm_write_time_us":5097,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:20:07.988001 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling LogGCOp(b3786700633b47d79f9c8fac23ea98f2): free 12018004 bytes of WAL
I20260812 06:20:07.988194 13686 log_reader.cc:385] T b3786700633b47d79f9c8fac23ea98f2: removed 1 log segments from log reader
I20260812 06:20:07.988256 13686 log.cc:1079] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: Deleting log segment in path: /tmp/dist-test-taskPUZM6R/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515598401013-13214-0/minicluster-data/ts-0-root/wals/b3786700633b47d79f9c8fac23ea98f2/wal-000000039 (ops 188-192)
I20260812 06:20:07.990836 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: LogGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:07.991163 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2): 463 bytes on disk
I20260812 06:20:07.991596 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: UndoDeltaBlockGCOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.992153 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:08.002053 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3465,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:20:08.002470 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2): perf score=1.000000
I20260812 06:20:08.179994 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: MajorDeltaCompactionOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.177s	user 0.133s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":749,"lbm_read_time_us":12689,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33095,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:08.180583 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=11.118625
I20260812 06:20:08.205812 13214 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.576s	user 1.675s	sys 0.165s
I20260812 06:20:08.234055 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.053s	user 0.035s	sys 0.015s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":22781,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:08.234681 13797 maintenance_manager.cc:419] P 53feb1c78d434a369ba10bd3cf1eaeaf: Scheduling FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2): perf score=2.188937
I20260812 06:20:08.237177 13214 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.001s	sys 0.000s
I20260812 06:20:08.237612 13214 tablet_server.cc:179] TabletServer@127.12.231.129:0 shutting down...
I20260812 06:20:08.245234 13686 maintenance_manager.cc:643] P 53feb1c78d434a369ba10bd3cf1eaeaf: FlushDeltaMemStoresOp(b3786700633b47d79f9c8fac23ea98f2) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.245643 13214 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:08.245867 13214 tablet_replica.cc:333] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf: stopping tablet replica
I20260812 06:20:08.245970 13214 raft_consensus.cc:2243] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.246124 13214 raft_consensus.cc:2272] T b3786700633b47d79f9c8fac23ea98f2 P 53feb1c78d434a369ba10bd3cf1eaeaf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.259145 13214 tablet_server.cc:196] TabletServer@127.12.231.129:0 shutdown complete.
I20260812 06:20:08.261929 13214 master.cc:562] Master@127.12.231.190:37075 shutting down...
I20260812 06:20:08.265146 13214 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.265304 13214 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.265370 13214 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5092abf6458f41d29e605c6db636bf4d: stopping tablet replica
I20260812 06:20:08.277463 13214 master.cc:584] Master@127.12.231.190:37075 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4896 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9933 ms total)

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