[==========] 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:52.862274  7698 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.132.190:34831
I20260812 06:17:52.863240  7698 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:52.863818  7698 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:52.870095  7698 server_base.cc:1061] running on GCE node
W20260812 06:17:52.870054  7710 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:52.870067  7708 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:52.870352  7706 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:52.870923  7698 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.871013  7698 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:52.871044  7698 hybrid_clock.cc:648] HybridClock initialized: now 1786515472871043 us; error 0 us; skew 500 ppm
I20260812 06:17:52.872776  7698 webserver.cc:533] Webserver started at http://127.7.132.190:45485/ using document root <none> and password file <none>
I20260812 06:17:52.873260  7698 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.873317  7698 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.873545  7698 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.875196  7698 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/master-0-root/instance:
uuid: "31e33b9d2e6b4bb4a022e4182e9a3910"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-39l8"
I20260812 06:17:52.878438  7698 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:52.880409  7721 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:52.881378  7698 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:52.881467  7698 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/master-0-root
uuid: "31e33b9d2e6b4bb4a022e4182e9a3910"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-39l8"
I20260812 06:17:52.881536  7698 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-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:52.894497  7698 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.895009  7698 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:52.895129  7698 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.902499  7698 rpc_server.cc:307] RPC server started. Bound to: 127.7.132.190:34831
I20260812 06:17:52.902518  7802 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.132.190:34831 every 8 connection(s)
I20260812 06:17:52.904665  7803 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:52.909789  7803 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910: Bootstrap starting.
I20260812 06:17:52.912127  7803 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:52.912979  7803 log.cc:826] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:52.914501  7803 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910: No bootstrap required, opened a new log
I20260812 06:17:52.917152  7803 raft_consensus.cc:359] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31e33b9d2e6b4bb4a022e4182e9a3910" member_type: VOTER }
I20260812 06:17:52.917305  7803 raft_consensus.cc:385] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:52.917346  7803 raft_consensus.cc:740] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 31e33b9d2e6b4bb4a022e4182e9a3910, State: Initialized, Role: FOLLOWER
I20260812 06:17:52.917883  7803 consensus_queue.cc:260] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [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: "31e33b9d2e6b4bb4a022e4182e9a3910" member_type: VOTER }
I20260812 06:17:52.918047  7803 raft_consensus.cc:399] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:52.918124  7803 raft_consensus.cc:493] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:52.918294  7803 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:52.919111  7803 raft_consensus.cc:515] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31e33b9d2e6b4bb4a022e4182e9a3910" member_type: VOTER }
I20260812 06:17:52.919533  7803 leader_election.cc:304] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [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: 31e33b9d2e6b4bb4a022e4182e9a3910; no voters: 
I20260812 06:17:52.919848  7803 leader_election.cc:290] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:52.919975  7807 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:52.920220  7807 raft_consensus.cc:697] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 1 LEADER]: Becoming Leader. State: Replica: 31e33b9d2e6b4bb4a022e4182e9a3910, State: Running, Role: LEADER
I20260812 06:17:52.920611  7807 consensus_queue.cc:237] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [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: "31e33b9d2e6b4bb4a022e4182e9a3910" member_type: VOTER }
I20260812 06:17:52.920871  7803 sys_catalog.cc:565] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:52.922433  7810 sys_catalog.cc:455] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 31e33b9d2e6b4bb4a022e4182e9a3910. Latest consensus state: current_term: 1 leader_uuid: "31e33b9d2e6b4bb4a022e4182e9a3910" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31e33b9d2e6b4bb4a022e4182e9a3910" member_type: VOTER } }
I20260812 06:17:52.922482  7809 sys_catalog.cc:455] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "31e33b9d2e6b4bb4a022e4182e9a3910" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "31e33b9d2e6b4bb4a022e4182e9a3910" member_type: VOTER } }
I20260812 06:17:52.922570  7809 sys_catalog.cc:458] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.922569  7810 sys_catalog.cc:458] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:52.923023  7826 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:52.923161  7698 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:52.925191  7826 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:52.929616  7826 catalog_manager.cc:1383] Generated new cluster ID: ee413f7e665c467d9370cdf41a9fbe1d
I20260812 06:17:52.929692  7826 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:52.938409  7826 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:52.939239  7826 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:52.944999  7826 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910: Generated new TSK 0
I20260812 06:17:52.945566  7826 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:52.955688  7698 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:52.958508  7846 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:52.958586  7845 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:52.958619  7698 server_base.cc:1061] running on GCE node
W20260812 06:17:52.958748  7849 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:52.958976  7698 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:52.959018  7698 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:52.959034  7698 hybrid_clock.cc:648] HybridClock initialized: now 1786515472959034 us; error 0 us; skew 500 ppm
I20260812 06:17:52.959921  7698 webserver.cc:533] Webserver started at http://127.7.132.129:38811/ using document root <none> and password file <none>
I20260812 06:17:52.960098  7698 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:52.960166  7698 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:52.960263  7698 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:52.960682  7698 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/instance:
uuid: "7ba814a65c92428e852e45786410c690"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-39l8"
I20260812 06:17:52.962193  7698 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:52.963312  7856 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:52.963585  7698 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:52.963660  7698 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root
uuid: "7ba814a65c92428e852e45786410c690"
format_stamp: "Formatted at 2026-08-12 06:17:52 on dist-test-slave-39l8"
I20260812 06:17:52.963748  7698 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-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:52.981855  7698 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:52.982298  7698 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:52.982841  7698 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:52.983687  7698 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:52.983738  7698 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.983809  7698 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:52.983852  7698 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:52.990808  7698 rpc_server.cc:307] RPC server started. Bound to: 127.7.132.129:42489
I20260812 06:17:52.990844  7952 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.132.129:42489 every 8 connection(s)
I20260812 06:17:53.003410  7955 heartbeater.cc:344] Connected to a master server at 127.7.132.190:34831
I20260812 06:17:53.003685  7955 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:53.004176  7955 heartbeater.cc:507] Master 127.7.132.190:34831 requested a full tablet report, sending...
I20260812 06:17:53.005646  7748 ts_manager.cc:194] Registered new tserver with Master: 7ba814a65c92428e852e45786410c690 (127.7.132.129:42489)
I20260812 06:17:53.005895  7698 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014458116s
I20260812 06:17:53.007242  7748 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44860
I20260812 06:17:53.015619  7748 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44868:
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:53.029757  7896 tablet_service.cc:1511] Processing CreateTablet for tablet ac0b0816b2344b31ad10064a72a8ba0b (DEFAULT_TABLE table=heavy-update-compaction-test [id=f5de520284ae42198c0242cfab11dc3e]), partition=
I20260812 06:17:53.030190  7896 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ac0b0816b2344b31ad10064a72a8ba0b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.032567  7971 tablet_bootstrap.cc:492] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Bootstrap starting.
I20260812 06:17:53.033699  7971 tablet_bootstrap.cc:654] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.034937  7971 tablet_bootstrap.cc:492] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: No bootstrap required, opened a new log
I20260812 06:17:53.035037  7971 ts_tablet_manager.cc:1403] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:53.035511  7971 raft_consensus.cc:359] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ba814a65c92428e852e45786410c690" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 42489 } }
I20260812 06:17:53.035641  7971 raft_consensus.cc:385] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.035676  7971 raft_consensus.cc:740] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7ba814a65c92428e852e45786410c690, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.035835  7971 consensus_queue.cc:260] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [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: "7ba814a65c92428e852e45786410c690" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 42489 } }
I20260812 06:17:53.035931  7971 raft_consensus.cc:399] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.036034  7971 raft_consensus.cc:493] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.036091  7971 raft_consensus.cc:3060] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.036927  7971 raft_consensus.cc:515] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ba814a65c92428e852e45786410c690" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 42489 } }
I20260812 06:17:53.037070  7971 leader_election.cc:304] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [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: 7ba814a65c92428e852e45786410c690; no voters: 
I20260812 06:17:53.037261  7971 leader_election.cc:290] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.037390  7973 raft_consensus.cc:2804] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.037632  7971 ts_tablet_manager.cc:1434] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:53.037672  7973 raft_consensus.cc:697] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 1 LEADER]: Becoming Leader. State: Replica: 7ba814a65c92428e852e45786410c690, State: Running, Role: LEADER
I20260812 06:17:53.037884  7973 consensus_queue.cc:237] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [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: "7ba814a65c92428e852e45786410c690" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 42489 } }
I20260812 06:17:53.038045  7955 heartbeater.cc:499] Master 127.7.132.190:34831 was elected leader, sending a full tablet report...
I20260812 06:17:53.040685  7748 catalog_manager.cc:5719] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7ba814a65c92428e852e45786410c690 (127.7.132.129). New cstate: current_term: 1 leader_uuid: "7ba814a65c92428e852e45786410c690" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ba814a65c92428e852e45786410c690" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 42489 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:53.107831  7698 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.012s	sys 0.015s
I20260812 06:17:53.241931  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=19.054940
I20260812 06:17:53.418113  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.176s	user 0.135s	sys 0.038s Metrics: {"bytes_written":13168993,"cfile_init":1,"compiler_manager_pool.queue_time_us":182,"delete_count":0,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":278,"dirs.run_wall_time_us":878,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45550,"lbm_writes_lt_1ms":778,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":183680,"thread_start_us":109,"threads_started":1,"update_count":1605}
I20260812 06:17:53.419335  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b): free 20743880 bytes of WAL
I20260812 06:17:53.419754  7861 log_reader.cc:385] T ac0b0816b2344b31ad10064a72a8ba0b: removed 2 log segments from log reader
I20260812 06:17:53.419906  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000001 (ops 1-6)
I20260812 06:17:53.420047  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000002 (ops 7-11)
I20260812 06:17:53.427006  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.007s	user 0.000s	sys 0.007s Metrics: {}
I20260812 06:17:53.427563  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:53.455824  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.028s	user 0.002s	sys 0.015s Metrics: {"bytes_written":3651384,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:17:53.456322  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b): 16411393 bytes on disk
I20260812 06:17:53.456971  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.457427  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:53.471285  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5326,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.471786  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:53.659574  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.188s	user 0.132s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774782,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":738,"lbm_read_time_us":13366,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29051,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13056,"thread_start_us":381,"threads_started":5,"update_count":2500}
I20260812 06:17:53.660197  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:53.701184  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.041s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18134,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.701704  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:53.712090  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.712498  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:53.843684  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.131s	user 0.117s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":8953,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26226,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:17:53.844419  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:53.886372  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.042s	user 0.020s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15315,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.886848  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:53.897084  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.897648  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:54.025789  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.128s	user 0.088s	sys 0.040s 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":198,"lbm_read_time_us":8759,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25351,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:54.026510  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:54.065716  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.039s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13684,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.066146  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:54.076516  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4106,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.077071  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:54.202394  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.125s	user 0.097s	sys 0.025s 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":300,"lbm_read_time_us":7505,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26306,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.203101  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:54.255371  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.052s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16441,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.255908  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:54.266392  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.266881  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:54.414155  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.147s	user 0.082s	sys 0.061s 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":157,"lbm_read_time_us":10550,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24809,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:17:54.414790  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:54.460549  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.046s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14496,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.461086  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:54.472509  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.473181  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:54.597419  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.123s	user 0.100s	sys 0.023s 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":635,"lbm_read_time_us":9566,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24189,"lbm_writes_lt_1ms":443,"mutex_wait_us":246,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:17:54.597922  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:54.642529  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.044s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15918,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.643078  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:54.657446  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.657972  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:54.690474  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1123,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2075,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:54.691287  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b): free 116849526 bytes of WAL
I20260812 06:17:54.691582  7861 log_reader.cc:385] T ac0b0816b2344b31ad10064a72a8ba0b: removed 12 log segments from log reader
I20260812 06:17:54.691628  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000003 (ops 12-16)
I20260812 06:17:54.691658  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000004 (ops 17-21)
I20260812 06:17:54.691720  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000005 (ops 22-26)
I20260812 06:17:54.691751  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000006 (ops 27-30)
I20260812 06:17:54.691787  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000007 (ops 31-35)
I20260812 06:17:54.691817  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000008 (ops 36-40)
I20260812 06:17:54.691849  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000009 (ops 41-44)
I20260812 06:17:54.691888  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000010 (ops 45-49)
I20260812 06:17:54.691926  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000011 (ops 50-54)
I20260812 06:17:54.691963  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000012 (ops 55-58)
I20260812 06:17:54.692015  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000013 (ops 59-63)
I20260812 06:17:54.692065  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000014 (ops 64-68)
I20260812 06:17:54.718086  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:54.718523  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b): 463 bytes on disk
I20260812 06:17:54.719071  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b) 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:54.719606  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=3.181125
I20260812 06:17:54.736528  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":5210311,"delete_count":0,"lbm_write_time_us":7115,"lbm_writes_lt_1ms":130,"reinsert_count":0,"update_count":635}
I20260812 06:17:54.736954  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.196750
I20260812 06:17:54.744678  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":2765,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:17:54.745100  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:54.920301  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.175s	user 0.113s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":474,"lbm_read_time_us":11786,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35428,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:17:54.920917  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:54.971134  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.050s	user 0.020s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18591,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.971633  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:54.983402  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.983829  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:55.144295  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.160s	user 0.117s	sys 0.032s 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":245,"lbm_read_time_us":10202,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31388,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:55.144932  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:55.202975  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.058s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22031,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.203469  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:55.213409  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.213943  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:55.391300  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.177s	user 0.104s	sys 0.070s 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":188,"lbm_read_time_us":13426,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28758,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2500}
I20260812 06:17:55.391942  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:55.442471  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.050s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22848,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.442998  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:55.606324  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.163s	user 0.104s	sys 0.058s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1441,"lbm_read_time_us":10525,"lbm_reads_lt_1ms":467,"lbm_write_time_us":29232,"lbm_writes_lt_1ms":443,"mutex_wait_us":579,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:17:55.606968  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=11.118625
I20260812 06:17:55.636662  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.029s	user 0.011s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12998,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:55.637338  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:55.650014  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4751,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.650430  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:55.776371  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.126s	user 0.091s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":392,"lbm_read_time_us":9399,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22681,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.776985  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:55.821431  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.044s	user 0.020s	sys 0.021s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19799,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.821990  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:55.833906  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.834357  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:55.955603  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.121s	user 0.101s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":811,"lbm_read_time_us":7774,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23017,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:55.956329  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=10.126437
I20260812 06:17:55.998950  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.042s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14972,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.999588  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:56.010285  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.011088  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:56.045136  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1279,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1501,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:56.045825  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b): free 120100331 bytes of WAL
I20260812 06:17:56.046082  7861 log_reader.cc:385] T ac0b0816b2344b31ad10064a72a8ba0b: removed 12 log segments from log reader
I20260812 06:17:56.046133  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000015 (ops 69-72)
I20260812 06:17:56.046162  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000016 (ops 73-77)
I20260812 06:17:56.046227  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000017 (ops 78-82)
I20260812 06:17:56.046258  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000018 (ops 83-87)
I20260812 06:17:56.046294  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000019 (ops 88-92)
I20260812 06:17:56.046336  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000020 (ops 93-96)
I20260812 06:17:56.046379  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000021 (ops 97-101)
I20260812 06:17:56.046418  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000022 (ops 102-106)
I20260812 06:17:56.046456  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000023 (ops 107-110)
I20260812 06:17:56.046494  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000024 (ops 111-115)
I20260812 06:17:56.046531  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000025 (ops 116-120)
I20260812 06:17:56.046568  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000026 (ops 121-125)
I20260812 06:17:56.071933  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:56.072382  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b): 447 bytes on disk
I20260812 06:17:56.073022  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.073566  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=3.181125
I20260812 06:17:56.091267  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.018s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7379,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:56.091663  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:56.101030  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3643,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.101404  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:56.273758  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.172s	user 0.130s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1250,"lbm_read_time_us":13157,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35418,"lbm_writes_lt_1ms":643,"mutex_wait_us":605,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:56.274269  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:56.330681  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.056s	user 0.019s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22749,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.331226  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:56.345996  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5555,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.346544  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:56.502621  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.156s	user 0.101s	sys 0.052s 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":647,"lbm_read_time_us":10342,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28180,"lbm_writes_lt_1ms":543,"mutex_wait_us":87,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:56.503559  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=11.118625
I20260812 06:17:56.540153  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.036s	user 0.019s	sys 0.015s Metrics: {"bytes_written":13210025,"delete_count":0,"lbm_write_time_us":16660,"lbm_writes_lt_1ms":325,"reinsert_count":0,"update_count":1610}
I20260812 06:17:56.540935  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:56.555183  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:56.555750  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:56.699152  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.143s	user 0.111s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672258,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":8981,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26400,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2000}
I20260812 06:17:56.700394  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=11.118625
I20260812 06:17:56.750108  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.050s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20052,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.750623  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:56.761952  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.762362  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:56.778920  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.016s	user 0.005s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3568,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.779356  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:56.974882  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.195s	user 0.125s	sys 0.057s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1197,"lbm_read_time_us":12642,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31278,"lbm_writes_lt_1ms":543,"mutex_wait_us":321,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:56.975363  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:57.019743  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.044s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17639,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.020267  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:57.034958  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.015s	user 0.010s	sys 0.004s 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:57.035476  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:57.208485  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.173s	user 0.088s	sys 0.076s 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":222,"lbm_read_time_us":13549,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":27937,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:17:57.209113  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:57.258388  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.049s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19027,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.259023  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:57.271987  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.272773  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:57.452582  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.180s	user 0.133s	sys 0.036s 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":180,"lbm_read_time_us":11565,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35004,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2500}
I20260812 06:17:57.453266  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=14.095187
I20260812 06:17:57.505391  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.052s	user 0.016s	sys 0.033s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22970,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.506008  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:57.518832  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.519347  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:57.552953  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushMRSOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.033s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1316,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1582,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:57.553696  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b): free 121006693 bytes of WAL
I20260812 06:17:57.553980  7861 log_reader.cc:385] T ac0b0816b2344b31ad10064a72a8ba0b: removed 12 log segments from log reader
I20260812 06:17:57.554035  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000027 (ops 126-130)
I20260812 06:17:57.554066  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000028 (ops 131-135)
I20260812 06:17:57.554136  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000029 (ops 136-140)
I20260812 06:17:57.554206  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000030 (ops 141-145)
I20260812 06:17:57.554276  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000031 (ops 146-150)
I20260812 06:17:57.554320  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000032 (ops 151-155)
I20260812 06:17:57.554382  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000033 (ops 156-160)
I20260812 06:17:57.554425  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000034 (ops 161-165)
I20260812 06:17:57.554466  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000035 (ops 166-170)
I20260812 06:17:57.554512  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000036 (ops 171-174)
I20260812 06:17:57.554554  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000037 (ops 175-179)
I20260812 06:17:57.554595  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000038 (ops 180-184)
I20260812 06:17:57.587150  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:57.587654  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=5.165500
I20260812 06:17:57.607980  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.020s	user 0.017s	sys 0.002s Metrics: {"bytes_written":6728210,"delete_count":0,"lbm_write_time_us":8452,"lbm_writes_lt_1ms":167,"reinsert_count":0,"update_count":820}
I20260812 06:17:57.608457  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b): free 11564893 bytes of WAL
I20260812 06:17:57.608711  7861 log_reader.cc:385] T ac0b0816b2344b31ad10064a72a8ba0b: removed 1 log segments from log reader
I20260812 06:17:57.608769  7861 log.cc:1079] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/ac0b0816b2344b31ad10064a72a8ba0b/wal-000000039 (ops 185-188)
I20260812 06:17:57.611958  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: LogGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:57.612423  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:57.627238  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":1477052,"delete_count":0,"lbm_write_time_us":1857,"lbm_writes_lt_1ms":39,"reinsert_count":0,"update_count":180}
I20260812 06:17:57.627710  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:57.850148  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.222s	user 0.129s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":661,"lbm_read_time_us":16304,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36778,"lbm_writes_lt_1ms":743,"mutex_wait_us":36,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8064,"thread_start_us":95,"threads_started":1,"update_count":3500}
I20260812 06:17:57.850909  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=18.063937
I20260812 06:17:57.899540  7698 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.791s	user 1.807s	sys 0.121s
I20260812 06:17:57.910157  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.059s	user 0.034s	sys 0.020s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":24850,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:57.910655  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b): 482 bytes on disk
I20260812 06:17:57.911046  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: UndoDeltaBlockGCOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.911561  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=2.188937
I20260812 06:17:57.921272  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: FlushDeltaMemStoresOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4186,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:17:57.921623  7957 maintenance_manager.cc:419] P 7ba814a65c92428e852e45786410c690: Scheduling MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b): perf score=1.000000
I20260812 06:17:57.981166  7698 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.002s	sys 0.000s
I20260812 06:17:57.981791  7698 tablet_server.cc:179] TabletServer@127.7.132.129:0 shutting down...
I20260812 06:17:58.074857  7861 maintenance_manager.cc:643] P 7ba814a65c92428e852e45786410c690: MajorDeltaCompactionOp(ac0b0816b2344b31ad10064a72a8ba0b) complete. Timing: real 0.153s	user 0.100s	sys 0.052s Metrics: {"cfile_cache_hit":261,"cfile_cache_hit_bytes":10669545,"cfile_cache_miss":371,"cfile_cache_miss_bytes":18207561,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":384,"lbm_read_time_us":8612,"lbm_reads_lt_1ms":403,"lbm_write_time_us":29842,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":124160,"update_count":3000}
I20260812 06:17:58.075661  7698 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:58.076067  7698 tablet_replica.cc:333] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690: stopping tablet replica
I20260812 06:17:58.076308  7698 raft_consensus.cc:2243] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.076545  7698 raft_consensus.cc:2272] T ac0b0816b2344b31ad10064a72a8ba0b P 7ba814a65c92428e852e45786410c690 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.082109  7698 tablet_server.cc:196] TabletServer@127.7.132.129:0 shutdown complete.
I20260812 06:17:58.127278  7698 master.cc:562] Master@127.7.132.190:34831 shutting down...
I20260812 06:17:58.131448  7698 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.131664  7698 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.131764  7698 tablet_replica.cc:333] T 00000000000000000000000000000000 P 31e33b9d2e6b4bb4a022e4182e9a3910: stopping tablet replica
I20260812 06:17:58.143961  7698 master.cc:584] Master@127.7.132.190:34831 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5371 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:58.245558  7698 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.132.190:45063
I20260812 06:17:58.245977  7698 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:58.248106  8000 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:58.248127  8007 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:58.248181  7698 server_base.cc:1061] running on GCE node
W20260812 06:17:58.248373  8010 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:58.248553  7698 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:58.248620  7698 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:58.248652  7698 hybrid_clock.cc:648] HybridClock initialized: now 1786515478248651 us; error 0 us; skew 500 ppm
I20260812 06:17:58.249436  7698 webserver.cc:533] Webserver started at http://127.7.132.190:38667/ using document root <none> and password file <none>
I20260812 06:17:58.249614  7698 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:58.249684  7698 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:58.249763  7698 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:58.250156  7698 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/master-0-root/instance:
uuid: "7b2011f2e38c4df693e1a1640315b5c6"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-39l8"
I20260812 06:17:58.251740  7698 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:58.252693  8019 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:58.252942  7698 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:58.253033  7698 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/master-0-root
uuid: "7b2011f2e38c4df693e1a1640315b5c6"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-39l8"
I20260812 06:17:58.253127  7698 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-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:58.262702  7698 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:58.263125  7698 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:58.267168  7698 rpc_server.cc:307] RPC server started. Bound to: 127.7.132.190:45063
I20260812 06:17:58.271986  8097 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.132.190:45063 every 8 connection(s)
I20260812 06:17:58.272500  8098 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:58.274300  8098 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6: Bootstrap starting.
I20260812 06:17:58.275207  8098 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:58.276263  8098 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6: No bootstrap required, opened a new log
I20260812 06:17:58.276648  8098 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b2011f2e38c4df693e1a1640315b5c6" member_type: VOTER }
I20260812 06:17:58.276755  8098 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:58.276821  8098 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7b2011f2e38c4df693e1a1640315b5c6, State: Initialized, Role: FOLLOWER
I20260812 06:17:58.277014  8098 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [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: "7b2011f2e38c4df693e1a1640315b5c6" member_type: VOTER }
I20260812 06:17:58.277139  8098 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:58.277186  8098 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:58.277242  8098 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:58.277910  8098 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b2011f2e38c4df693e1a1640315b5c6" member_type: VOTER }
I20260812 06:17:58.278057  8098 leader_election.cc:304] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [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: 7b2011f2e38c4df693e1a1640315b5c6; no voters: 
I20260812 06:17:58.278276  8098 leader_election.cc:290] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:58.278395  8106 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:58.278625  8106 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 1 LEADER]: Becoming Leader. State: Replica: 7b2011f2e38c4df693e1a1640315b5c6, State: Running, Role: LEADER
I20260812 06:17:58.278755  8098 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:58.278784  8106 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [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: "7b2011f2e38c4df693e1a1640315b5c6" member_type: VOTER }
I20260812 06:17:58.279174  8107 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7b2011f2e38c4df693e1a1640315b5c6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b2011f2e38c4df693e1a1640315b5c6" member_type: VOTER } }
I20260812 06:17:58.279191  8108 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7b2011f2e38c4df693e1a1640315b5c6. Latest consensus state: current_term: 1 leader_uuid: "7b2011f2e38c4df693e1a1640315b5c6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7b2011f2e38c4df693e1a1640315b5c6" member_type: VOTER } }
I20260812 06:17:58.279315  8107 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:58.279381  8108 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:58.279841  8114 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:58.280493  8114 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:58.280652  7698 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:58.282272  8114 catalog_manager.cc:1383] Generated new cluster ID: de111b68c47b4ec990dceaa62bc00a1c
I20260812 06:17:58.282328  8114 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:58.297915  8114 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:58.298492  8114 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:58.306169  8114 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6: Generated new TSK 0
I20260812 06:17:58.306342  8114 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:58.312981  7698 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:58.314937  8137 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:58.314989  8139 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:58.315186  7698 server_base.cc:1061] running on GCE node
W20260812 06:17:58.315028  8136 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:58.315506  7698 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:58.315548  7698 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:58.315563  7698 hybrid_clock.cc:648] HybridClock initialized: now 1786515478315564 us; error 0 us; skew 500 ppm
I20260812 06:17:58.316457  7698 webserver.cc:533] Webserver started at http://127.7.132.129:38853/ using document root <none> and password file <none>
I20260812 06:17:58.316633  7698 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:58.316712  7698 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:58.316798  7698 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:58.317222  7698 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/instance:
uuid: "a043c552ad894e9bb0d94dcdfd34819a"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-39l8"
I20260812 06:17:58.318756  7698 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:58.319677  8148 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:58.319927  7698 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:58.320000  7698 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root
uuid: "a043c552ad894e9bb0d94dcdfd34819a"
format_stamp: "Formatted at 2026-08-12 06:17:58 on dist-test-slave-39l8"
I20260812 06:17:58.320058  7698 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-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:58.333629  7698 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:58.334002  7698 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:58.334275  7698 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:58.334805  7698 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:58.334846  7698 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:58.334903  7698 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:58.334939  7698 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:58.339155  7698 rpc_server.cc:307] RPC server started. Bound to: 127.7.132.129:32971
I20260812 06:17:58.339219  8255 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.132.129:32971 every 8 connection(s)
I20260812 06:17:58.347391  8256 heartbeater.cc:344] Connected to a master server at 127.7.132.190:45063
I20260812 06:17:58.347527  8256 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:58.347760  8256 heartbeater.cc:507] Master 127.7.132.190:45063 requested a full tablet report, sending...
I20260812 06:17:58.348413  8045 ts_manager.cc:194] Registered new tserver with Master: a043c552ad894e9bb0d94dcdfd34819a (127.7.132.129:32971)
I20260812 06:17:58.348526  7698 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008912682s
I20260812 06:17:58.349176  8045 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40360
I20260812 06:17:58.355814  8045 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40366:
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:58.364365  8196 tablet_service.cc:1511] Processing CreateTablet for tablet a4fefa56314f4a37b2e5915cf4d38e34 (DEFAULT_TABLE table=heavy-update-compaction-test [id=62bb199abe794295952d4a137e9e251b]), partition=
I20260812 06:17:58.364643  8196 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a4fefa56314f4a37b2e5915cf4d38e34. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:58.366559  8279 tablet_bootstrap.cc:492] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Bootstrap starting.
I20260812 06:17:58.367467  8279 tablet_bootstrap.cc:654] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:58.368417  8279 tablet_bootstrap.cc:492] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: No bootstrap required, opened a new log
I20260812 06:17:58.368486  8279 ts_tablet_manager.cc:1403] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:58.368815  8279 raft_consensus.cc:359] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a043c552ad894e9bb0d94dcdfd34819a" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 32971 } }
I20260812 06:17:58.368899  8279 raft_consensus.cc:385] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:58.368921  8279 raft_consensus.cc:740] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a043c552ad894e9bb0d94dcdfd34819a, State: Initialized, Role: FOLLOWER
I20260812 06:17:58.369076  8279 consensus_queue.cc:260] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [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: "a043c552ad894e9bb0d94dcdfd34819a" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 32971 } }
I20260812 06:17:58.369167  8279 raft_consensus.cc:399] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:58.369192  8279 raft_consensus.cc:493] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:58.369222  8279 raft_consensus.cc:3060] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:58.370211  8279 raft_consensus.cc:515] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a043c552ad894e9bb0d94dcdfd34819a" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 32971 } }
I20260812 06:17:58.370325  8279 leader_election.cc:304] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [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: a043c552ad894e9bb0d94dcdfd34819a; no voters: 
I20260812 06:17:58.370469  8279 leader_election.cc:290] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:58.370597  8282 raft_consensus.cc:2804] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:58.370826  8279 ts_tablet_manager.cc:1434] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:58.370826  8256 heartbeater.cc:499] Master 127.7.132.190:45063 was elected leader, sending a full tablet report...
I20260812 06:17:58.370826  8282 raft_consensus.cc:697] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 1 LEADER]: Becoming Leader. State: Replica: a043c552ad894e9bb0d94dcdfd34819a, State: Running, Role: LEADER
I20260812 06:17:58.371032  8282 consensus_queue.cc:237] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [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: "a043c552ad894e9bb0d94dcdfd34819a" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 32971 } }
I20260812 06:17:58.372228  8045 catalog_manager.cc:5719] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a reported cstate change: term changed from 0 to 1, leader changed from <none> to a043c552ad894e9bb0d94dcdfd34819a (127.7.132.129). New cstate: current_term: 1 leader_uuid: "a043c552ad894e9bb0d94dcdfd34819a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a043c552ad894e9bb0d94dcdfd34819a" member_type: VOTER last_known_addr { host: "127.7.132.129" port: 32971 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:58.426997  7698 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.010s	sys 0.012s
I20260812 06:17:58.590138  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=23.023690
I20260812 06:17:58.755250  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.165s	user 0.117s	sys 0.047s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":160,"dirs.run_wall_time_us":978,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44987,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:58.755884  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34): free 20743880 bytes of WAL
I20260812 06:17:58.756100  8155 log_reader.cc:385] T a4fefa56314f4a37b2e5915cf4d38e34: removed 2 log segments from log reader
I20260812 06:17:58.756165  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000001 (ops 1-6)
I20260812 06:17:58.756220  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000002 (ops 7-11)
I20260812 06:17:58.760478  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.004s	user 0.003s	sys 0.000s Metrics: {}
I20260812 06:17:58.760804  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:58.775733  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.015s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.776194  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:17:58.928169  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.152s	user 0.084s	sys 0.062s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":429,"lbm_read_time_us":8975,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25284,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":325,"threads_started":5,"update_count":2000}
I20260812 06:17:58.928910  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=11.118625
I20260812 06:17:58.965314  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.036s	user 0.032s	sys 0.001s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15417,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"mutex_wait_us":29,"reinsert_count":0,"update_count":1550}
I20260812 06:17:58.965936  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34): 20513808 bytes on disk
I20260812 06:17:58.966367  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.966909  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:58.993537  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.026s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.994168  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:59.006150  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4788,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.006510  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:17:59.186224  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.180s	user 0.138s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":653,"lbm_read_time_us":13072,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29225,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:17:59.186883  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:17:59.235694  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.049s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20886,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.236207  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:59.258364  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.022s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5614,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.258885  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:17:59.432704  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.174s	user 0.116s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":786,"lbm_read_time_us":12474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26905,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:17:59.433305  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:17:59.483232  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.048s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22093,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.483719  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:59.496208  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4591,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.496701  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:17:59.672206  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.175s	user 0.113s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":11723,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29288,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:59.673053  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:17:59.722105  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.049s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18785,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.722579  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:59.732810  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.733544  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:17:59.891141  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.157s	user 0.117s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":763,"lbm_read_time_us":9976,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30886,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:17:59.891716  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:17:59.936789  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.045s	user 0.039s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19167,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.937376  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:17:59.951489  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.952056  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:17:59.982009  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.030s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1382,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1378,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:59.982844  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34): free 124257235 bytes of WAL
I20260812 06:17:59.983126  8155 log_reader.cc:385] T a4fefa56314f4a37b2e5915cf4d38e34: removed 12 log segments from log reader
I20260812 06:17:59.983206  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000003 (ops 12-16)
I20260812 06:17:59.983274  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000004 (ops 17-21)
I20260812 06:17:59.983325  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000005 (ops 22-26)
I20260812 06:17:59.983361  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000006 (ops 27-31)
I20260812 06:17:59.983405  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000007 (ops 32-36)
I20260812 06:17:59.983440  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000008 (ops 37-41)
I20260812 06:17:59.983485  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000009 (ops 42-46)
I20260812 06:17:59.983532  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000010 (ops 47-51)
I20260812 06:17:59.983570  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000011 (ops 52-56)
I20260812 06:17:59.983606  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000012 (ops 57-60)
I20260812 06:17:59.983641  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000013 (ops 61-65)
I20260812 06:17:59.983676  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000014 (ops 66-70)
I20260812 06:18:00.012346  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:00.012833  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34): 473 bytes on disk
I20260812 06:18:00.013306  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.013995  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=5.165500
I20260812 06:18:00.041793  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.028s	user 0.017s	sys 0.007s Metrics: {"bytes_written":6400018,"delete_count":0,"lbm_write_time_us":7483,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:18:00.042371  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:00.052838  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2072,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:18:00.053435  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:00.280805  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.227s	user 0.140s	sys 0.087s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":224,"lbm_read_time_us":16118,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36302,"lbm_writes_lt_1ms":743,"mutex_wait_us":271,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:18:00.281488  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=18.063937
I20260812 06:18:00.345258  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.064s	user 0.052s	sys 0.008s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27847,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:00.345774  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:00.360486  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5566,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.360991  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:00.566830  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.206s	user 0.141s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":15080,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32700,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:18:00.567615  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:00.609678  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.042s	user 0.029s	sys 0.010s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18130,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:00.610126  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:00.633266  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":5392,"lbm_writes_lt_1ms":106,"mutex_wait_us":84,"reinsert_count":0,"update_count":515}
I20260812 06:18:00.633752  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:00.643961  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:00.644384  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:00.850937  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.206s	user 0.142s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":288,"lbm_read_time_us":14090,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34076,"lbm_writes_lt_1ms":643,"mutex_wait_us":101,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:00.851675  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=15.087375
I20260812 06:18:00.900938  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":17558578,"delete_count":0,"lbm_write_time_us":20787,"lbm_writes_lt_1ms":431,"mutex_wait_us":844,"reinsert_count":0,"update_count":2140}
I20260812 06:18:00.901554  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.196750
I20260812 06:18:00.918071  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.016s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3408,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:00.918556  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:00.932890  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.933364  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:01.135281  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.202s	user 0.119s	sys 0.082s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918187,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":810,"lbm_read_time_us":15677,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31268,"lbm_writes_lt_1ms":643,"mutex_wait_us":354,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:18:01.135879  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=15.087375
I20260812 06:18:01.179141  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.043s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19259,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:01.179787  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:01.194193  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5445,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.194769  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:01.359555  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.165s	user 0.112s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815671,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1050,"lbm_read_time_us":10967,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29059,"lbm_writes_lt_1ms":543,"mutex_wait_us":288,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:18:01.360191  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:01.419337  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.059s	user 0.046s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25343,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.420123  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:01.432080  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.432545  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:01.460613  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.028s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1236,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1674,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":896}
I20260812 06:18:01.461242  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34): free 124710330 bytes of WAL
I20260812 06:18:01.461473  8155 log_reader.cc:385] T a4fefa56314f4a37b2e5915cf4d38e34: removed 12 log segments from log reader
I20260812 06:18:01.461519  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000015 (ops 71-75)
I20260812 06:18:01.461547  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000016 (ops 76-80)
I20260812 06:18:01.461597  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000017 (ops 81-85)
I20260812 06:18:01.461640  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000018 (ops 86-90)
I20260812 06:18:01.461707  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000019 (ops 91-95)
I20260812 06:18:01.461751  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000020 (ops 96-100)
I20260812 06:18:01.461798  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000021 (ops 101-105)
I20260812 06:18:01.461838  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000022 (ops 106-110)
I20260812 06:18:01.461879  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000023 (ops 111-115)
I20260812 06:18:01.461917  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000024 (ops 116-120)
I20260812 06:18:01.461961  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000025 (ops 121-125)
I20260812 06:18:01.462004  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000026 (ops 126-130)
I20260812 06:18:01.488893  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:01.489349  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=3.181125
I20260812 06:18:01.501483  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4533,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:01.501902  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:01.511631  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3725,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.512049  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34): 472 bytes on disk
I20260812 06:18:01.512442  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:01.512913  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:01.731232  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.218s	user 0.144s	sys 0.074s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":951,"lbm_read_time_us":16076,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40659,"lbm_writes_lt_1ms":743,"mutex_wait_us":42,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:18:01.734534  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=18.063937
I20260812 06:18:01.795261  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.060s	user 0.045s	sys 0.014s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26640,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:01.795722  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=3.181125
I20260812 06:18:01.807583  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4715,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:01.808002  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:01.817790  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3669,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:01.819545  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:02.011448  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.192s	user 0.131s	sys 0.060s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020617,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":771,"lbm_read_time_us":15983,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40883,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":3500}
I20260812 06:18:02.012282  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:02.081131  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.066s	user 0.023s	sys 0.035s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":29508,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.081635  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=3.181125
I20260812 06:18:02.093611  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4467,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:02.094033  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:02.103250  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3474,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:02.103660  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:02.269119  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.165s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":663,"lbm_read_time_us":12995,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31821,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":3000}
I20260812 06:18:02.269625  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:02.322095  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.052s	user 0.012s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22038,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.322619  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:02.337096  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.337607  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:02.499617  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.162s	user 0.121s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":10140,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31221,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:02.502885  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:02.560869  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.058s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22399,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.561380  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:02.571502  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.572144  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:02.733397  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.161s	user 0.106s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":11038,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25808,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:02.734082  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:02.777329  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.043s	user 0.021s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18998,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.777930  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:02.807021  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushMRSOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1486,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2000,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:02.807797  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34): free 112692558 bytes of WAL
I20260812 06:18:02.808061  8155 log_reader.cc:385] T a4fefa56314f4a37b2e5915cf4d38e34: removed 11 log segments from log reader
I20260812 06:18:02.808127  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000027 (ops 131-135)
I20260812 06:18:02.808166  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000028 (ops 136-140)
I20260812 06:18:02.808189  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000029 (ops 141-145)
I20260812 06:18:02.808212  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000030 (ops 146-150)
I20260812 06:18:02.808234  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000031 (ops 151-155)
I20260812 06:18:02.808269  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000032 (ops 156-160)
I20260812 06:18:02.808300  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000033 (ops 161-165)
I20260812 06:18:02.808329  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000034 (ops 166-170)
I20260812 06:18:02.808357  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000035 (ops 171-175)
I20260812 06:18:02.808385  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000036 (ops 176-180)
I20260812 06:18:02.808430  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000037 (ops 181-185)
I20260812 06:18:02.834343  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:02.834885  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34): 462 bytes on disk
I20260812 06:18:02.835363  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: UndoDeltaBlockGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:02.835934  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=3.181125
I20260812 06:18:02.847353  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4445,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:02.847786  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34): free 8767195 bytes of WAL
I20260812 06:18:02.847997  8155 log_reader.cc:385] T a4fefa56314f4a37b2e5915cf4d38e34: removed 1 log segments from log reader
I20260812 06:18:02.848042  8155 log.cc:1079] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: Deleting log segment in path: /tmp/dist-test-taskjKAo6Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515472852048-7698-0/minicluster-data/ts-0-root/wals/a4fefa56314f4a37b2e5915cf4d38e34/wal-000000038 (ops 186-190)
I20260812 06:18:02.849777  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: LogGCOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:02.850106  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=2.188937
I20260812 06:18:02.860353  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:02.861054  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:03.078931  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.218s	user 0.129s	sys 0.088s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":968,"lbm_read_time_us":14075,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38064,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:18:03.079712  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=14.095187
I20260812 06:18:03.123685  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: FlushDeltaMemStoresOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.044s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19151,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.124552  8258 maintenance_manager.cc:419] P a043c552ad894e9bb0d94dcdfd34819a: Scheduling MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34): perf score=1.000000
I20260812 06:18:03.143906  7698 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.717s	user 1.780s	sys 0.144s
I20260812 06:18:03.203171  7698 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.002s	sys 0.000s
I20260812 06:18:03.203688  7698 tablet_server.cc:179] TabletServer@127.7.132.129:0 shutting down...
I20260812 06:18:03.249612  8155 maintenance_manager.cc:643] P a043c552ad894e9bb0d94dcdfd34819a: MajorDeltaCompactionOp(a4fefa56314f4a37b2e5915cf4d38e34) complete. Timing: real 0.125s	user 0.101s	sys 0.023s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":456,"lbm_read_time_us":11194,"lbm_reads_lt_1ms":459,"lbm_write_time_us":20799,"lbm_writes_lt_1ms":443,"mutex_wait_us":64,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":41472,"update_count":2000}
I20260812 06:18:03.250514  7698 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:03.250837  7698 tablet_replica.cc:333] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a: stopping tablet replica
I20260812 06:18:03.250968  7698 raft_consensus.cc:2243] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:03.251155  7698 raft_consensus.cc:2272] T a4fefa56314f4a37b2e5915cf4d38e34 P a043c552ad894e9bb0d94dcdfd34819a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:03.258349  7698 tablet_server.cc:196] TabletServer@127.7.132.129:0 shutdown complete.
I20260812 06:18:03.287626  7698 master.cc:562] Master@127.7.132.190:45063 shutting down...
I20260812 06:18:03.291421  7698 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:03.291612  7698 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:03.291703  7698 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7b2011f2e38c4df693e1a1640315b5c6: stopping tablet replica
I20260812 06:18:03.303895  7698 master.cc:584] Master@127.7.132.190:45063 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5156 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10528 ms total)

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