[==========] 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:17:25.761014 11921 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.164.126:37591
I20260812 06:17:25.762120 11921 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:17:25.762773 11921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:25.769775 11930 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:25.769857 11926 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:25.770056 11921 server_base.cc:1061] running on GCE node
W20260812 06:17:25.770069 11927 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:17:25.770607 11921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:25.770735 11921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:25.770797 11921 hybrid_clock.cc:648] HybridClock initialized: now 1786515445770793 us; error 0 us; skew 500 ppm
I20260812 06:17:25.772766 11921 webserver.cc:533] Webserver started at http://127.11.164.126:42669/ using document root <none> and password file <none>
I20260812 06:17:25.773372 11921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:25.773461 11921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:25.773728 11921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:25.775398 11921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/master-0-root/instance:
uuid: "1012c568f2dd443b99fe254467ac43d3"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-27sr"
I20260812 06:17:25.779102 11921 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:25.781570 11935 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.782603 11921 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:25.782738 11921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/master-0-root
uuid: "1012c568f2dd443b99fe254467ac43d3"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-27sr"
I20260812 06:17:25.782850 11921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:25.814020 11921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:25.814733 11921 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:17:25.814929 11921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:25.822930 11921 rpc_server.cc:307] RPC server started. Bound to: 127.11.164.126:37591
I20260812 06:17:25.822940 11998 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.164.126:37591 every 8 connection(s)
I20260812 06:17:25.825382 11999 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:25.830971 11999 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3: Bootstrap starting.
I20260812 06:17:25.833365 11999 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:25.834275 11999 log.cc:826] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:25.836061 11999 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3: No bootstrap required, opened a new log
I20260812 06:17:25.838958 11999 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1012c568f2dd443b99fe254467ac43d3" member_type: VOTER }
I20260812 06:17:25.839128 11999 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:25.839171 11999 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1012c568f2dd443b99fe254467ac43d3, State: Initialized, Role: FOLLOWER
I20260812 06:17:25.839823 11999 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [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: "1012c568f2dd443b99fe254467ac43d3" member_type: VOTER }
I20260812 06:17:25.839991 11999 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:25.840045 11999 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:25.840132 11999 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:25.840893 11999 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1012c568f2dd443b99fe254467ac43d3" member_type: VOTER }
I20260812 06:17:25.841290 11999 leader_election.cc:304] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [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: 1012c568f2dd443b99fe254467ac43d3; no voters: 
I20260812 06:17:25.841560 11999 leader_election.cc:290] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:25.841711 12003 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:25.842000 12003 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 1 LEADER]: Becoming Leader. State: Replica: 1012c568f2dd443b99fe254467ac43d3, State: Running, Role: LEADER
I20260812 06:17:25.842429 12003 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [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: "1012c568f2dd443b99fe254467ac43d3" member_type: VOTER }
I20260812 06:17:25.842694 11999 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:25.844448 12005 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1012c568f2dd443b99fe254467ac43d3. Latest consensus state: current_term: 1 leader_uuid: "1012c568f2dd443b99fe254467ac43d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1012c568f2dd443b99fe254467ac43d3" member_type: VOTER } }
I20260812 06:17:25.844499 12004 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1012c568f2dd443b99fe254467ac43d3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1012c568f2dd443b99fe254467ac43d3" member_type: VOTER } }
I20260812 06:17:25.844568 12005 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:25.844605 12004 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:25.844928 12019 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:25.845103 11921 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:25.847221 12019 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:25.852166 12019 catalog_manager.cc:1383] Generated new cluster ID: 7653ebb56b174baaa612d849fe7c3f5c
I20260812 06:17:25.852255 12019 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:25.876950 12019 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:25.877915 12019 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:25.889462 12019 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3: Generated new TSK 0
I20260812 06:17:25.890321 12019 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:25.910043 11921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:25.913055 12029 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:25.913129 12027 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:25.913074 12031 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:25.913278 11921 server_base.cc:1061] running on GCE node
I20260812 06:17:25.913578 11921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:25.913645 11921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:25.913671 11921 hybrid_clock.cc:648] HybridClock initialized: now 1786515445913671 us; error 0 us; skew 500 ppm
I20260812 06:17:25.914752 11921 webserver.cc:533] Webserver started at http://127.11.164.65:43349/ using document root <none> and password file <none>
I20260812 06:17:25.914932 11921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:25.915002 11921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:25.915088 11921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:25.915537 11921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/instance:
uuid: "82dcda1682be42808ab0b83d93cedb8c"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-27sr"
I20260812 06:17:25.917344 11921 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:25.918558 12036 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.918874 11921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:25.918941 11921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root
uuid: "82dcda1682be42808ab0b83d93cedb8c"
format_stamp: "Formatted at 2026-08-12 06:17:25 on dist-test-slave-27sr"
I20260812 06:17:25.919034 11921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:25.936545 11921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:25.937076 11921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:25.937667 11921 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:25.938609 11921 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:25.938681 11921 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.938761 11921 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:25.938799 11921 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:25.946597 11921 rpc_server.cc:307] RPC server started. Bound to: 127.11.164.65:44297
I20260812 06:17:25.946674 12110 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.164.65:44297 every 8 connection(s)
I20260812 06:17:25.958271 12111 heartbeater.cc:344] Connected to a master server at 127.11.164.126:37591
I20260812 06:17:25.958582 12111 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:25.959178 12111 heartbeater.cc:507] Master 127.11.164.126:37591 requested a full tablet report, sending...
I20260812 06:17:25.960966 11956 ts_manager.cc:194] Registered new tserver with Master: 82dcda1682be42808ab0b83d93cedb8c (127.11.164.65:44297)
I20260812 06:17:25.961087 11921 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013761943s
I20260812 06:17:25.962590 11956 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56522
I20260812 06:17:25.972463 11956 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56534:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:25.989562 12068 tablet_service.cc:1511] Processing CreateTablet for tablet b6eb7e51e24e4d9f99c700e6ed7a7c64 (DEFAULT_TABLE table=heavy-update-compaction-test [id=cd59acf70fe3478b897711df4c362a8b]), partition=
I20260812 06:17:25.990099 12068 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b6eb7e51e24e4d9f99c700e6ed7a7c64. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:25.992941 12126 tablet_bootstrap.cc:492] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Bootstrap starting.
I20260812 06:17:25.994095 12126 tablet_bootstrap.cc:654] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:25.995442 12126 tablet_bootstrap.cc:492] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: No bootstrap required, opened a new log
I20260812 06:17:25.995599 12126 ts_tablet_manager.cc:1403] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:25.996444 12126 raft_consensus.cc:359] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82dcda1682be42808ab0b83d93cedb8c" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 44297 } }
I20260812 06:17:25.996606 12126 raft_consensus.cc:385] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:25.996649 12126 raft_consensus.cc:740] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 82dcda1682be42808ab0b83d93cedb8c, State: Initialized, Role: FOLLOWER
I20260812 06:17:25.996830 12126 consensus_queue.cc:260] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [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: "82dcda1682be42808ab0b83d93cedb8c" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 44297 } }
I20260812 06:17:25.996989 12126 raft_consensus.cc:399] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:25.997058 12126 raft_consensus.cc:493] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:25.997133 12126 raft_consensus.cc:3060] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:25.998157 12126 raft_consensus.cc:515] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82dcda1682be42808ab0b83d93cedb8c" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 44297 } }
I20260812 06:17:25.998351 12126 leader_election.cc:304] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [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: 82dcda1682be42808ab0b83d93cedb8c; no voters: 
I20260812 06:17:25.998636 12126 leader_election.cc:290] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:25.998759 12128 raft_consensus.cc:2804] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:25.998971 12128 raft_consensus.cc:697] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 1 LEADER]: Becoming Leader. State: Replica: 82dcda1682be42808ab0b83d93cedb8c, State: Running, Role: LEADER
I20260812 06:17:25.999084 12126 ts_tablet_manager.cc:1434] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:17:25.999228 12128 consensus_queue.cc:237] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [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: "82dcda1682be42808ab0b83d93cedb8c" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 44297 } }
I20260812 06:17:25.999527 12111 heartbeater.cc:499] Master 127.11.164.126:37591 was elected leader, sending a full tablet report...
I20260812 06:17:26.002702 11956 catalog_manager.cc:5719] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c reported cstate change: term changed from 0 to 1, leader changed from <none> to 82dcda1682be42808ab0b83d93cedb8c (127.11.164.65). New cstate: current_term: 1 leader_uuid: "82dcda1682be42808ab0b83d93cedb8c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "82dcda1682be42808ab0b83d93cedb8c" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 44297 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:26.070884 11921 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.021s	sys 0.008s
I20260812 06:17:26.197908 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=15.086190
I20260812 06:17:26.362866 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.165s	user 0.125s	sys 0.032s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":197,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1010,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39269,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":129,"threads_started":1,"update_count":1450}
I20260812 06:17:26.364326 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): free 20743880 bytes of WAL
I20260812 06:17:26.364704 12041 log_reader.cc:385] T b6eb7e51e24e4d9f99c700e6ed7a7c64: removed 2 log segments from log reader
I20260812 06:17:26.364794 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000001 (ops 1-6)
I20260812 06:17:26.364876 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000002 (ops 7-11)
I20260812 06:17:26.371055 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.007s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:26.371539 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:26.393262 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.022s	user 0.015s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.393851 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): 12719217 bytes on disk
I20260812 06:17:26.394484 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:26.394954 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:26.541019 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.146s	user 0.118s	sys 0.027s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":917,"lbm_read_time_us":8014,"lbm_reads_lt_1ms":450,"lbm_write_time_us":28716,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":419,"threads_started":5,"update_count":1950}
I20260812 06:17:26.541706 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:26.585197 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.043s	user 0.018s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19001,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.585798 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:26.603281 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.017s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.603885 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:26.747126 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.143s	user 0.089s	sys 0.054s 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":577,"lbm_read_time_us":9252,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28376,"lbm_writes_lt_1ms":443,"mutex_wait_us":350,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:26.747798 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:26.786656 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.039s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16699,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.787165 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:26.798146 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.798697 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:26.920881 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.122s	user 0.106s	sys 0.016s 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":819,"lbm_read_time_us":9158,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22288,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:17:26.921484 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:26.980680 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.059s	user 0.030s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20996,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:26.981276 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:26.992617 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:26.993090 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:27.150188 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.157s	user 0.113s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":11174,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24683,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:17:27.150885 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:27.192324 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.041s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18761,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.192852 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:27.209120 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.209591 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:27.343971 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.134s	user 0.097s	sys 0.037s 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":779,"lbm_read_time_us":10164,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26989,"lbm_writes_lt_1ms":443,"mutex_wait_us":417,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:17:27.344687 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:27.393565 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.046s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18334,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.394258 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:27.406656 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4433,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.407182 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:27.549870 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.142s	user 0.114s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":608,"lbm_read_time_us":11279,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27269,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":89472,"update_count":2000}
I20260812 06:17:27.550489 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:27.593405 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.043s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14945,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.593946 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:27.605566 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.606182 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:27.747648 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.141s	user 0.104s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":967,"lbm_read_time_us":10991,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22897,"lbm_writes_lt_1ms":443,"mutex_wait_us":283,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:17:27.748426 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:27.792285 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.044s	user 0.028s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17062,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:27.792968 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:27.804862 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:27.805577 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:27.839808 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.034s	user 0.024s	sys 0.008s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1465,"drs_written":1,"lbm_read_time_us":105,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1666,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:27.840723 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): free 124257246 bytes of WAL
I20260812 06:17:27.840968 12041 log_reader.cc:385] T b6eb7e51e24e4d9f99c700e6ed7a7c64: removed 12 log segments from log reader
I20260812 06:17:27.841014 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000003 (ops 12-16)
I20260812 06:17:27.841043 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000004 (ops 17-21)
I20260812 06:17:27.841109 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000005 (ops 22-26)
I20260812 06:17:27.841142 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000006 (ops 27-31)
I20260812 06:17:27.841183 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000007 (ops 32-36)
I20260812 06:17:27.841235 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000008 (ops 37-40)
I20260812 06:17:27.841276 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000009 (ops 41-45)
I20260812 06:17:27.841325 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000010 (ops 46-50)
I20260812 06:17:27.841363 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000011 (ops 51-55)
I20260812 06:17:27.841403 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000012 (ops 56-60)
I20260812 06:17:27.841441 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000013 (ops 61-65)
I20260812 06:17:27.841481 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000014 (ops 66-70)
I20260812 06:17:27.869879 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:27.870424 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): 483 bytes on disk
I20260812 06:17:27.871280 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:27.871802 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=6.157687
I20260812 06:17:27.906260 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.034s	user 0.024s	sys 0.008s Metrics: {"bytes_written":7589714,"delete_count":0,"lbm_write_time_us":10868,"lbm_writes_lt_1ms":188,"reinsert_count":0,"update_count":925}
I20260812 06:17:27.906831 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:28.116050 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.209s	user 0.149s	sys 0.051s Metrics: {"cfile_cache_miss":618,"cfile_cache_miss_bytes":28261857,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1333,"lbm_read_time_us":15647,"lbm_reads_lt_1ms":654,"lbm_write_time_us":33740,"lbm_writes_lt_1ms":628,"mutex_wait_us":812,"peak_mem_usage":72846179,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":102,"threads_started":1,"update_count":2925}
I20260812 06:17:28.116820 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=15.087375
I20260812 06:17:28.182237 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.065s	user 0.035s	sys 0.027s Metrics: {"bytes_written":17025270,"delete_count":0,"lbm_write_time_us":23762,"lbm_writes_lt_1ms":418,"reinsert_count":0,"update_count":2075}
I20260812 06:17:28.182875 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:28.199015 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.199551 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:28.376780 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.177s	user 0.125s	sys 0.051s Metrics: {"cfile_cache_miss":547,"cfile_cache_miss_bytes":25390057,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1621,"lbm_read_time_us":13021,"lbm_reads_lt_1ms":587,"lbm_write_time_us":31297,"lbm_writes_lt_1ms":558,"mutex_wait_us":359,"peak_mem_usage":64771809,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2575}
I20260812 06:17:28.377599 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:28.412715 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.035s	user 0.013s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.413372 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:28.430014 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.430743 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:28.568226 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.137s	user 0.110s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":851,"lbm_read_time_us":9312,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25144,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:17:28.569089 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:28.615032 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.046s	user 0.020s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17943,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.615506 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:28.626961 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.627686 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:28.765000 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.137s	user 0.113s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1262,"lbm_read_time_us":9412,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24012,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2000}
I20260812 06:17:28.765730 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:28.817796 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.052s	user 0.027s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19996,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.818321 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:28.829281 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.830122 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:28.952960 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.123s	user 0.097s	sys 0.024s 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":762,"lbm_read_time_us":7867,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22930,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:28.953433 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:29.008316 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.055s	user 0.020s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15721,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.008993 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:29.025393 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.025988 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:29.169941 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.144s	user 0.107s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1356,"lbm_read_time_us":11180,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22011,"lbm_writes_lt_1ms":443,"mutex_wait_us":339,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:17:29.170724 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:29.210477 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17169,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.210956 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:29.223312 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.223757 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:29.362818 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.139s	user 0.110s	sys 0.029s 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":217,"lbm_read_time_us":10014,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27452,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:17:29.363638 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:29.409763 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.046s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17517,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.410295 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:29.421842 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4100,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.422386 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:29.454291 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.032s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":211,"dirs.run_wall_time_us":1405,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1866,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:29.454993 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): free 129320528 bytes of WAL
I20260812 06:17:29.455220 12041 log_reader.cc:385] T b6eb7e51e24e4d9f99c700e6ed7a7c64: removed 13 log segments from log reader
I20260812 06:17:29.455281 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000015 (ops 71-75)
I20260812 06:17:29.455327 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000016 (ops 76-80)
I20260812 06:17:29.455389 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000017 (ops 81-85)
I20260812 06:17:29.455431 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000018 (ops 86-90)
I20260812 06:17:29.455471 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000019 (ops 91-95)
I20260812 06:17:29.455513 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000020 (ops 96-100)
I20260812 06:17:29.455550 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000021 (ops 101-104)
I20260812 06:17:29.455590 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000022 (ops 105-109)
I20260812 06:17:29.455629 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000023 (ops 110-114)
I20260812 06:17:29.455668 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000024 (ops 115-118)
I20260812 06:17:29.455708 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000025 (ops 119-123)
I20260812 06:17:29.455749 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000026 (ops 124-128)
I20260812 06:17:29.455796 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000027 (ops 129-133)
I20260812 06:17:29.483405 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:29.483814 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=3.181125
I20260812 06:17:29.498922 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":5087240,"delete_count":0,"lbm_write_time_us":5997,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:17:29.499413 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.196750
I20260812 06:17:29.509441 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":3798,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:17:29.510193 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): 482 bytes on disk
I20260812 06:17:29.510905 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":132,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.511637 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:29.681190 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.169s	user 0.155s	sys 0.012s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":171,"lbm_read_time_us":13490,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32911,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20096,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:17:29.681928 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=14.095187
I20260812 06:17:29.737957 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.056s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22177,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.738549 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:29.750979 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.751509 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:29.931228 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.180s	user 0.122s	sys 0.047s 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":1289,"lbm_read_time_us":12312,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34890,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":73216,"update_count":2500}
I20260812 06:17:29.932052 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=14.095187
I20260812 06:17:29.980039 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.048s	user 0.022s	sys 0.025s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19604,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.980548 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:30.131919 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.151s	user 0.106s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":343,"lbm_read_time_us":9396,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25532,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.132725 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=11.118625
I20260812 06:17:30.169018 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.036s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15432,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:30.169662 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:30.186340 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5761,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.187034 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:30.321838 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.135s	user 0.111s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":694,"lbm_read_time_us":9658,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26818,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:17:30.322625 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:30.361316 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.038s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14162,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.361867 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:30.372890 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.373399 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:30.499722 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.126s	user 0.104s	sys 0.020s 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":508,"lbm_read_time_us":9081,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22947,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":73728,"update_count":2000}
I20260812 06:17:30.500504 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:30.534443 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.034s	user 0.010s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14237,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.534982 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:30.545900 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.546342 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:30.668119 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.122s	user 0.077s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":421,"lbm_read_time_us":9205,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22278,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2000}
I20260812 06:17:30.668838 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:30.726740 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.058s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15900,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.727357 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:30.738322 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.738827 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:30.895744 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.157s	user 0.100s	sys 0.056s 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":1574,"lbm_read_time_us":11781,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25406,"lbm_writes_lt_1ms":443,"mutex_wait_us":352,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:30.896628 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=10.126437
I20260812 06:17:30.945309 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.048s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17361,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:30.946028 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=2.188937
I20260812 06:17:30.962225 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.962769 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:31.000710 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushMRSOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.038s	user 0.036s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1213,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1779,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:31.001494 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): free 124710518 bytes of WAL
I20260812 06:17:31.001720 12041 log_reader.cc:385] T b6eb7e51e24e4d9f99c700e6ed7a7c64: removed 12 log segments from log reader
I20260812 06:17:31.001793 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000028 (ops 134-138)
I20260812 06:17:31.001847 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000029 (ops 139-143)
I20260812 06:17:31.001904 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000030 (ops 144-148)
I20260812 06:17:31.001945 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000031 (ops 149-153)
I20260812 06:17:31.001981 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000032 (ops 154-158)
I20260812 06:17:31.002017 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000033 (ops 159-163)
I20260812 06:17:31.002055 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000034 (ops 164-168)
I20260812 06:17:31.002092 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000035 (ops 169-173)
I20260812 06:17:31.002128 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000036 (ops 174-178)
I20260812 06:17:31.002166 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000037 (ops 179-183)
I20260812 06:17:31.002203 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000038 (ops 184-188)
I20260812 06:17:31.002239 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000039 (ops 189-193)
I20260812 06:17:31.032548 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:31.032969 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): 483 bytes on disk
I20260812 06:17:31.033469 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: UndoDeltaBlockGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.034085 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=5.165500
I20260812 06:17:31.060317 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: FlushDeltaMemStoresOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.026s	user 0.009s	sys 0.017s Metrics: {"bytes_written":7220497,"delete_count":0,"lbm_write_time_us":7997,"lbm_writes_lt_1ms":179,"reinsert_count":0,"update_count":880}
I20260812 06:17:31.061139 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): free 12018006 bytes of WAL
I20260812 06:17:31.061432 12041 log_reader.cc:385] T b6eb7e51e24e4d9f99c700e6ed7a7c64: removed 1 log segments from log reader
I20260812 06:17:31.061496 12041 log.cc:1079] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b6eb7e51e24e4d9f99c700e6ed7a7c64/wal-000000040 (ops 194-198)
I20260812 06:17:31.065207 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: LogGCOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:31.065757 12112 maintenance_manager.cc:419] P 82dcda1682be42808ab0b83d93cedb8c: Scheduling MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64): perf score=1.000000
I20260812 06:17:31.100848 11921 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.030s	user 1.858s	sys 0.163s
I20260812 06:17:31.197170 11921 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.096s	user 0.004s	sys 0.000s
I20260812 06:17:31.198031 11921 tablet_server.cc:179] TabletServer@127.11.164.65:0 shutting down...
I20260812 06:17:31.243916 12041 maintenance_manager.cc:643] P 82dcda1682be42808ab0b83d93cedb8c: MajorDeltaCompactionOp(b6eb7e51e24e4d9f99c700e6ed7a7c64) complete. Timing: real 0.178s	user 0.125s	sys 0.052s Metrics: {"cfile_cache_miss":609,"cfile_cache_miss_bytes":27892640,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1116,"lbm_read_time_us":15020,"lbm_reads_lt_1ms":641,"lbm_write_time_us":30705,"lbm_writes_lt_1ms":619,"mutex_wait_us":94,"peak_mem_usage":72476864,"reinsert_count":0,"spinlock_wait_cycles":16768,"thread_start_us":85,"threads_started":1,"update_count":2880}
I20260812 06:17:31.244751 11921 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:31.245364 11921 tablet_replica.cc:333] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c: stopping tablet replica
I20260812 06:17:31.245616 11921 raft_consensus.cc:2243] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.245868 11921 raft_consensus.cc:2272] T b6eb7e51e24e4d9f99c700e6ed7a7c64 P 82dcda1682be42808ab0b83d93cedb8c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.251948 11921 tablet_server.cc:196] TabletServer@127.11.164.65:0 shutdown complete.
I20260812 06:17:31.294250 11921 master.cc:562] Master@127.11.164.126:37591 shutting down...
I20260812 06:17:31.298086 11921 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:31.298319 11921 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:31.298418 11921 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1012c568f2dd443b99fe254467ac43d3: stopping tablet replica
I20260812 06:17:31.310945 11921 master.cc:584] Master@127.11.164.126:37591 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5638 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:31.413355 11921 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.164.126:35873
I20260812 06:17:31.413812 11921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.415987 12147 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:31.416024 12151 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:31.416091 11921 server_base.cc:1061] running on GCE node
W20260812 06:17:31.416038 12148 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:17:31.416484 11921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.416550 11921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:31.416584 11921 hybrid_clock.cc:648] HybridClock initialized: now 1786515451416582 us; error 0 us; skew 500 ppm
I20260812 06:17:31.417441 11921 webserver.cc:533] Webserver started at http://127.11.164.126:42365/ using document root <none> and password file <none>
I20260812 06:17:31.417632 11921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.417706 11921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.417862 11921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.418319 11921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/master-0-root/instance:
uuid: "0cead902d6934b5bb6435f9a38e377a7"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-27sr"
I20260812 06:17:31.419966 11921 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:31.421020 12160 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.421335 11921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:31.421445 11921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/master-0-root
uuid: "0cead902d6934b5bb6435f9a38e377a7"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-27sr"
I20260812 06:17:31.421546 11921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:31.431334 11921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.431985 11921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.437019 11921 rpc_server.cc:307] RPC server started. Bound to: 127.11.164.126:35873
I20260812 06:17:31.439983 12226 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.164.126:35873 every 8 connection(s)
I20260812 06:17:31.441079 12227 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.442925 12227 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7: Bootstrap starting.
I20260812 06:17:31.443732 12227 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.444917 12227 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7: No bootstrap required, opened a new log
I20260812 06:17:31.445361 12227 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cead902d6934b5bb6435f9a38e377a7" member_type: VOTER }
I20260812 06:17:31.445453 12227 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.445477 12227 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0cead902d6934b5bb6435f9a38e377a7, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.445681 12227 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [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: "0cead902d6934b5bb6435f9a38e377a7" member_type: VOTER }
I20260812 06:17:31.445772 12227 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.445798 12227 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.445829 12227 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.446529 12227 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cead902d6934b5bb6435f9a38e377a7" member_type: VOTER }
I20260812 06:17:31.446643 12227 leader_election.cc:304] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [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: 0cead902d6934b5bb6435f9a38e377a7; no voters: 
I20260812 06:17:31.446811 12227 leader_election.cc:290] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.446965 12231 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.447216 12231 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 1 LEADER]: Becoming Leader. State: Replica: 0cead902d6934b5bb6435f9a38e377a7, State: Running, Role: LEADER
I20260812 06:17:31.447335 12227 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:31.447379 12231 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [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: "0cead902d6934b5bb6435f9a38e377a7" member_type: VOTER }
I20260812 06:17:31.447840 12233 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0cead902d6934b5bb6435f9a38e377a7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cead902d6934b5bb6435f9a38e377a7" member_type: VOTER } }
I20260812 06:17:31.447857 12234 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0cead902d6934b5bb6435f9a38e377a7. Latest consensus state: current_term: 1 leader_uuid: "0cead902d6934b5bb6435f9a38e377a7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0cead902d6934b5bb6435f9a38e377a7" member_type: VOTER } }
I20260812 06:17:31.448033 12234 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.448318 12237 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:31.448349 12233 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:31.449155 12237 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:31.449460 11921 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:31.451113 12237 catalog_manager.cc:1383] Generated new cluster ID: fb319f5ae16a43b2995c5159d5d1b996
I20260812 06:17:31.451164 12237 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:31.464416 12237 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:31.465054 12237 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:31.473982 12237 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7: Generated new TSK 0
I20260812 06:17:31.474197 12237 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:31.482019 11921 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:31.484292 12253 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:31.484380 12252 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:31.484396 11921 server_base.cc:1061] running on GCE node
W20260812 06:17:31.484512 12256 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:31.484717 11921 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:31.484783 11921 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:31.484819 11921 hybrid_clock.cc:648] HybridClock initialized: now 1786515451484817 us; error 0 us; skew 500 ppm
I20260812 06:17:31.485715 11921 webserver.cc:533] Webserver started at http://127.11.164.65:45639/ using document root <none> and password file <none>
I20260812 06:17:31.485924 11921 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:31.485999 11921 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:31.486080 11921 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:31.486497 11921 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/instance:
uuid: "6c71175752ff4d1f8168311aa3551b50"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-27sr"
I20260812 06:17:31.488106 11921 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:31.489095 12262 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.489362 11921 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:31.489451 11921 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root
uuid: "6c71175752ff4d1f8168311aa3551b50"
format_stamp: "Formatted at 2026-08-12 06:17:31 on dist-test-slave-27sr"
I20260812 06:17:31.489534 11921 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:31.498778 11921 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:31.499171 11921 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:31.499468 11921 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:31.499984 11921 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:31.500042 11921 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.500097 11921 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:31.500149 11921 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:31.504642 11921 rpc_server.cc:307] RPC server started. Bound to: 127.11.164.65:34329
I20260812 06:17:31.506779 12338 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.164.65:34329 every 8 connection(s)
I20260812 06:17:31.510818 12339 heartbeater.cc:344] Connected to a master server at 127.11.164.126:35873
I20260812 06:17:31.510938 12339 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:31.511170 12339 heartbeater.cc:507] Master 127.11.164.126:35873 requested a full tablet report, sending...
I20260812 06:17:31.511943 12180 ts_manager.cc:194] Registered new tserver with Master: 6c71175752ff4d1f8168311aa3551b50 (127.11.164.65:34329)
I20260812 06:17:31.512292 11921 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006696786s
I20260812 06:17:31.513015 12180 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33258
I20260812 06:17:31.519632 12180 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33274:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:31.529138 12295 tablet_service.cc:1511] Processing CreateTablet for tablet b4a2eb35e1ac4baabd1e7aa6f35ed72f (DEFAULT_TABLE table=heavy-update-compaction-test [id=dd5a851cfc014f5fab643c2aa801df3b]), partition=
I20260812 06:17:31.529460 12295 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b4a2eb35e1ac4baabd1e7aa6f35ed72f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:31.531486 12355 tablet_bootstrap.cc:492] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Bootstrap starting.
I20260812 06:17:31.532449 12355 tablet_bootstrap.cc:654] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:31.533500 12355 tablet_bootstrap.cc:492] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: No bootstrap required, opened a new log
I20260812 06:17:31.533617 12355 ts_tablet_manager.cc:1403] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:31.534132 12355 raft_consensus.cc:359] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c71175752ff4d1f8168311aa3551b50" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 34329 } }
I20260812 06:17:31.534265 12355 raft_consensus.cc:385] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:31.534302 12355 raft_consensus.cc:740] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6c71175752ff4d1f8168311aa3551b50, State: Initialized, Role: FOLLOWER
I20260812 06:17:31.534430 12355 consensus_queue.cc:260] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [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: "6c71175752ff4d1f8168311aa3551b50" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 34329 } }
I20260812 06:17:31.534549 12355 raft_consensus.cc:399] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:31.534600 12355 raft_consensus.cc:493] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:31.534644 12355 raft_consensus.cc:3060] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:31.535385 12355 raft_consensus.cc:515] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c71175752ff4d1f8168311aa3551b50" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 34329 } }
I20260812 06:17:31.535499 12355 leader_election.cc:304] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [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: 6c71175752ff4d1f8168311aa3551b50; no voters: 
I20260812 06:17:31.535669 12355 leader_election.cc:290] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:31.535856 12357 raft_consensus.cc:2804] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:31.535995 12357 raft_consensus.cc:697] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 1 LEADER]: Becoming Leader. State: Replica: 6c71175752ff4d1f8168311aa3551b50, State: Running, Role: LEADER
I20260812 06:17:31.536037 12339 heartbeater.cc:499] Master 127.11.164.126:35873 was elected leader, sending a full tablet report...
I20260812 06:17:31.536034 12355 ts_tablet_manager.cc:1434] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:31.536125 12357 consensus_queue.cc:237] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [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: "6c71175752ff4d1f8168311aa3551b50" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 34329 } }
I20260812 06:17:31.537467 12180 catalog_manager.cc:5719] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6c71175752ff4d1f8168311aa3551b50 (127.11.164.65). New cstate: current_term: 1 leader_uuid: "6c71175752ff4d1f8168311aa3551b50" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c71175752ff4d1f8168311aa3551b50" member_type: VOTER last_known_addr { host: "127.11.164.65" port: 34329 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:31.602131 11921 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.017s	sys 0.008s
I20260812 06:17:31.757398 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=19.054940
I20260812 06:17:31.933969 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.176s	user 0.115s	sys 0.060s Metrics: {"bytes_written":13168991,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1405,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44182,"lbm_writes_lt_1ms":778,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1920,"update_count":1605}
I20260812 06:17:31.934739 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): free 20290830 bytes of WAL
I20260812 06:17:31.934988 12267 log_reader.cc:385] T b4a2eb35e1ac4baabd1e7aa6f35ed72f: removed 2 log segments from log reader
I20260812 06:17:31.935060 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000001 (ops 1-6)
I20260812 06:17:31.935117 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000002 (ops 7-10)
I20260812 06:17:31.939931 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:31.940414 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): 16411392 bytes on disk
I20260812 06:17:31.941035 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:17:31.941774 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=3.181125
I20260812 06:17:31.954979 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4512906,"delete_count":0,"lbm_write_time_us":5347,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:31.955474 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.196750
I20260812 06:17:31.965605 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3190,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:31.966351 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:32.164352 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.198s	user 0.137s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774777,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1641,"lbm_read_time_us":14288,"lbm_reads_lt_1ms":569,"lbm_write_time_us":32704,"lbm_writes_lt_1ms":543,"mutex_wait_us":398,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"thread_start_us":399,"threads_started":5,"update_count":2500}
I20260812 06:17:32.164958 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:32.228271 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.063s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19244,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.228849 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:32.239967 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.240490 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:32.428371 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.188s	user 0.090s	sys 0.085s 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":188,"lbm_read_time_us":12404,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29699,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":63232,"update_count":2500}
I20260812 06:17:32.429129 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:32.490088 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.061s	user 0.028s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23423,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.490691 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:32.501957 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.502472 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:32.697993 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.195s	user 0.126s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":690,"lbm_read_time_us":13103,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32076,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":2500}
I20260812 06:17:32.698751 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:32.752441 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.054s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":26132,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:32.753018 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:32.777518 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.024s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4592,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.778095 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:32.962473 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.184s	user 0.128s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1156,"lbm_read_time_us":12819,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32151,"lbm_writes_lt_1ms":543,"mutex_wait_us":442,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2500}
I20260812 06:17:32.963294 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:33.011497 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.048s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21021,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.012162 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:33.035355 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.023s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6398,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.035838 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:33.063740 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.028s	user 0.012s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.064585 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:33.286454 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.222s	user 0.155s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1993,"lbm_read_time_us":15044,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36780,"lbm_writes_lt_1ms":643,"mutex_wait_us":577,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":3000}
I20260812 06:17:33.287160 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:33.353745 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.066s	user 0.029s	sys 0.030s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22163,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:33.354465 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:33.365873 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.366400 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:33.415210 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.049s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1490,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1682,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:33.415879 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): free 121006430 bytes of WAL
I20260812 06:17:33.416165 12267 log_reader.cc:385] T b4a2eb35e1ac4baabd1e7aa6f35ed72f: removed 12 log segments from log reader
I20260812 06:17:33.416210 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000003 (ops 11-15)
I20260812 06:17:33.416239 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000004 (ops 16-20)
I20260812 06:17:33.416301 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000005 (ops 21-25)
I20260812 06:17:33.416344 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000006 (ops 26-30)
I20260812 06:17:33.416384 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000007 (ops 31-35)
I20260812 06:17:33.416425 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000008 (ops 36-40)
I20260812 06:17:33.416464 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000009 (ops 41-44)
I20260812 06:17:33.416507 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000010 (ops 45-49)
I20260812 06:17:33.416548 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000011 (ops 50-54)
I20260812 06:17:33.416572 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000012 (ops 55-59)
I20260812 06:17:33.416610 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000013 (ops 60-64)
I20260812 06:17:33.416654 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000014 (ops 65-69)
I20260812 06:17:33.443830 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:33.444449 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): 481 bytes on disk
I20260812 06:17:33.445137 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":105,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.445706 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:33.464592 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.019s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.465054 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:33.475669 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.476250 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:33.736955 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.260s	user 0.140s	sys 0.118s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":771,"lbm_read_time_us":19769,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45111,"lbm_writes_lt_1ms":743,"mutex_wait_us":327,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":108,"threads_started":1,"update_count":3500}
I20260812 06:17:33.737700 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=18.063937
I20260812 06:17:33.804328 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.066s	user 0.051s	sys 0.015s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29998,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:33.804998 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:33.822150 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.822717 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:34.060918 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.238s	user 0.120s	sys 0.108s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":814,"lbm_read_time_us":15541,"lbm_reads_lt_1ms":672,"lbm_write_time_us":40044,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":3000}
I20260812 06:17:34.061650 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=18.063937
I20260812 06:17:34.124385 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.063s	user 0.047s	sys 0.015s Metrics: {"bytes_written":20512312,"delete_count":0,"lbm_write_time_us":28508,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:34.124878 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:34.137367 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4910,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.137980 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:34.316223 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.178s	user 0.150s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":398,"lbm_read_time_us":14601,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35752,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":100992,"update_count":3000}
I20260812 06:17:34.316972 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:34.366495 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21522,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.367120 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:34.384888 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.018s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.385397 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:34.540198 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.155s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1213,"lbm_read_time_us":10010,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28415,"lbm_writes_lt_1ms":543,"mutex_wait_us":507,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:17:34.540992 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=12.110812
I20260812 06:17:34.590024 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":13661281,"delete_count":0,"lbm_write_time_us":20545,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1665}
I20260812 06:17:34.590508 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.196750
I20260812 06:17:34.602299 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.012s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3204,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:17:34.602807 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:34.612742 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3734,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.613221 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:34.806535 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.193s	user 0.141s	sys 0.041s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774770,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":921,"lbm_read_time_us":13819,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31861,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:17:34.807265 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:34.873498 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.066s	user 0.025s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24573,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:34.874025 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:34.884781 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4018,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.885423 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:34.917872 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.032s	user 0.028s	sys 0.002s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1432,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2020,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:34.918586 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): free 124257255 bytes of WAL
I20260812 06:17:34.918895 12267 log_reader.cc:385] T b4a2eb35e1ac4baabd1e7aa6f35ed72f: removed 12 log segments from log reader
I20260812 06:17:34.918958 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000015 (ops 70-74)
I20260812 06:17:34.918999 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000016 (ops 75-79)
I20260812 06:17:34.919032 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000017 (ops 80-84)
I20260812 06:17:34.919055 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000018 (ops 85-88)
I20260812 06:17:34.919083 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000019 (ops 89-93)
I20260812 06:17:34.919118 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000020 (ops 94-98)
I20260812 06:17:34.919150 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000021 (ops 99-103)
I20260812 06:17:34.919179 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000022 (ops 104-108)
I20260812 06:17:34.919205 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000023 (ops 109-113)
I20260812 06:17:34.919232 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000024 (ops 114-118)
I20260812 06:17:34.919263 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000025 (ops 119-123)
I20260812 06:17:34.919298 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000026 (ops 124-128)
I20260812 06:17:34.950696 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.032s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:17:34.951116 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=3.181125
I20260812 06:17:34.980648 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.029s	user 0.016s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7656,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.981144 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): 463 bytes on disk
I20260812 06:17:34.981601 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.982326 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:34.999733 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6614,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.000515 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:35.241590 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.241s	user 0.152s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":211,"lbm_read_time_us":18621,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42055,"lbm_writes_lt_1ms":743,"mutex_wait_us":50,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:35.242364 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=18.063937
I20260812 06:17:35.301390 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.059s	user 0.037s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":26974,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:35.301908 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:35.312911 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4406,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.313488 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:35.489887 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.176s	user 0.132s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":385,"lbm_read_time_us":13474,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35171,"lbm_writes_lt_1ms":643,"mutex_wait_us":100,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":3000}
I20260812 06:17:35.490609 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:35.547217 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.056s	user 0.039s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.547757 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:35.559010 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.559490 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:35.724063 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.164s	user 0.122s	sys 0.024s 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":441,"lbm_read_time_us":11718,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29469,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:35.724885 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:35.782233 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.057s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21343,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.782727 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:35.794247 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.794755 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:36.005661 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.211s	user 0.134s	sys 0.063s 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":1184,"lbm_read_time_us":12820,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33838,"lbm_writes_lt_1ms":543,"mutex_wait_us":377,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31616,"update_count":2500}
I20260812 06:17:36.006507 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:36.058637 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.052s	user 0.020s	sys 0.029s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23135,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.059217 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:36.215574 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.156s	user 0.102s	sys 0.053s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672161,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":150,"lbm_read_time_us":10508,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23936,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:17:36.216395 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:36.265043 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.048s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21189,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.265581 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:36.277633 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.278311 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:36.466096 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.188s	user 0.103s	sys 0.081s 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":389,"lbm_read_time_us":13219,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30260,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:17:36.466867 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=14.095187
I20260812 06:17:36.520982 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.054s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24495,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.521528 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:36.534085 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.534554 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:36.564724 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushMRSOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":1516,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1966,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:36.565470 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): free 129773835 bytes of WAL
I20260812 06:17:36.565753 12267 log_reader.cc:385] T b4a2eb35e1ac4baabd1e7aa6f35ed72f: removed 13 log segments from log reader
I20260812 06:17:36.565817 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000027 (ops 129-133)
I20260812 06:17:36.565858 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000028 (ops 134-138)
I20260812 06:17:36.565889 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000029 (ops 139-143)
I20260812 06:17:36.565912 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000030 (ops 144-148)
I20260812 06:17:36.565972 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000031 (ops 149-153)
I20260812 06:17:36.566001 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000032 (ops 154-158)
I20260812 06:17:36.566025 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000033 (ops 159-163)
I20260812 06:17:36.566056 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000034 (ops 164-168)
I20260812 06:17:36.566085 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000035 (ops 169-172)
I20260812 06:17:36.566113 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000036 (ops 173-177)
I20260812 06:17:36.566143 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000037 (ops 178-182)
I20260812 06:17:36.566175 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000038 (ops 183-187)
I20260812 06:17:36.566206 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000039 (ops 188-192)
I20260812 06:17:36.598378 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:36.601617 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): 494 bytes on disk
I20260812 06:17:36.602136 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: UndoDeltaBlockGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.602917 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:36.625573 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.023s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.626031 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): free 11564893 bytes of WAL
I20260812 06:17:36.626233 12267 log_reader.cc:385] T b4a2eb35e1ac4baabd1e7aa6f35ed72f: removed 1 log segments from log reader
I20260812 06:17:36.626292 12267 log.cc:1079] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: Deleting log segment in path: /tmp/dist-test-taskHX4hSP/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515445749388-11921-0/minicluster-data/ts-0-root/wals/b4a2eb35e1ac4baabd1e7aa6f35ed72f/wal-000000040 (ops 193-196)
I20260812 06:17:36.628654 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: LogGCOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:36.628950 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=2.188937
I20260812 06:17:36.639636 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: FlushDeltaMemStoresOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.640460 12340 maintenance_manager.cc:419] P 6c71175752ff4d1f8168311aa3551b50: Scheduling MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f): perf score=1.000000
I20260812 06:17:36.730486 11921 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.128s	user 1.921s	sys 0.159s
I20260812 06:17:36.833747 11921 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.103s	user 0.002s	sys 0.000s
I20260812 06:17:36.834399 11921 tablet_server.cc:179] TabletServer@127.11.164.65:0 shutting down...
I20260812 06:17:36.852381 12267 maintenance_manager.cc:643] P 6c71175752ff4d1f8168311aa3551b50: MajorDeltaCompactionOp(b4a2eb35e1ac4baabd1e7aa6f35ed72f) complete. Timing: real 0.212s	user 0.151s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":246,"lbm_read_time_us":15302,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33094,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:17:36.853070 11921 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:36.853503 11921 tablet_replica.cc:333] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50: stopping tablet replica
I20260812 06:17:36.853658 11921 raft_consensus.cc:2243] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.853850 11921 raft_consensus.cc:2272] T b4a2eb35e1ac4baabd1e7aa6f35ed72f P 6c71175752ff4d1f8168311aa3551b50 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.861219 11921 tablet_server.cc:196] TabletServer@127.11.164.65:0 shutdown complete.
I20260812 06:17:36.911036 11921 master.cc:562] Master@127.11.164.126:35873 shutting down...
I20260812 06:17:36.914558 11921 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:36.914783 11921 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:36.914875 11921 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0cead902d6934b5bb6435f9a38e377a7: stopping tablet replica
I20260812 06:17:36.928133 11921 master.cc:584] Master@127.11.164.126:35873 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5619 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11258 ms total)

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