[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:03.127892 19705 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.62.126:36351
I20260812 06:20:03.129017 19705 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:03.129667 19705 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:03.136658 19720 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:03.136706 19705 server_base.cc:1061] running on GCE node
W20260812 06:20:03.136688 19713 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.137012 19710 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:03.137537 19705 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:03.137630 19705 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:03.137656 19705 hybrid_clock.cc:648] HybridClock initialized: now 1786515603137655 us; error 0 us; skew 500 ppm
I20260812 06:20:03.139446 19705 webserver.cc:533] Webserver started at http://127.19.62.126:46877/ using document root <none> and password file <none>
I20260812 06:20:03.139984 19705 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:03.140039 19705 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:03.140239 19705 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:03.141973 19705 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/master-0-root/instance:
uuid: "7c273aa702644f03bece77cbbd87875a"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-zh2d"
I20260812 06:20:03.145624 19705 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:03.147784 19727 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.148949 19705 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:03.149070 19705 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/master-0-root
uuid: "7c273aa702644f03bece77cbbd87875a"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-zh2d"
I20260812 06:20:03.149154 19705 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:03.178545 19705 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:03.179216 19705 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:03.179359 19705 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:03.187830 19705 rpc_server.cc:307] RPC server started. Bound to: 127.19.62.126:36351
I20260812 06:20:03.187852 19810 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.62.126:36351 every 8 connection(s)
I20260812 06:20:03.190668 19812 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:03.196477 19812 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a: Bootstrap starting.
I20260812 06:20:03.198987 19812 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:03.199947 19812 log.cc:826] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:03.201952 19812 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a: No bootstrap required, opened a new log
I20260812 06:20:03.204770 19812 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7c273aa702644f03bece77cbbd87875a" member_type: VOTER }
I20260812 06:20:03.204954 19812 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:03.205092 19812 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7c273aa702644f03bece77cbbd87875a, State: Initialized, Role: FOLLOWER
I20260812 06:20:03.205729 19812 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [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: "7c273aa702644f03bece77cbbd87875a" member_type: VOTER }
I20260812 06:20:03.205904 19812 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:03.205973 19812 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:03.206146 19812 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:03.206948 19812 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7c273aa702644f03bece77cbbd87875a" member_type: VOTER }
I20260812 06:20:03.207410 19812 leader_election.cc:304] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [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: 7c273aa702644f03bece77cbbd87875a; no voters: 
I20260812 06:20:03.207775 19812 leader_election.cc:290] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:03.207864 19817 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:03.208164 19817 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 1 LEADER]: Becoming Leader. State: Replica: 7c273aa702644f03bece77cbbd87875a, State: Running, Role: LEADER
I20260812 06:20:03.208586 19817 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [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: "7c273aa702644f03bece77cbbd87875a" member_type: VOTER }
I20260812 06:20:03.208920 19812 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:03.210781 19820 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7c273aa702644f03bece77cbbd87875a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7c273aa702644f03bece77cbbd87875a" member_type: VOTER } }
I20260812 06:20:03.210904 19820 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:03.211143 19822 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7c273aa702644f03bece77cbbd87875a. Latest consensus state: current_term: 1 leader_uuid: "7c273aa702644f03bece77cbbd87875a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7c273aa702644f03bece77cbbd87875a" member_type: VOTER } }
I20260812 06:20:03.211225 19822 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:03.211426 19831 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:03.211727 19705 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:03.213979 19831 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:03.219116 19831 catalog_manager.cc:1383] Generated new cluster ID: 4205929be8a9408289565d9338c91b1d
I20260812 06:20:03.219208 19831 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:03.241356 19831 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:03.242609 19831 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:03.255064 19831 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a: Generated new TSK 0
I20260812 06:20:03.255900 19831 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:03.276561 19705 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:03.279524 19849 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.279467 19850 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:03.279466 19853 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:03.279902 19705 server_base.cc:1061] running on GCE node
I20260812 06:20:03.280084 19705 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:03.280139 19705 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:03.280165 19705 hybrid_clock.cc:648] HybridClock initialized: now 1786515603280164 us; error 0 us; skew 500 ppm
I20260812 06:20:03.281144 19705 webserver.cc:533] Webserver started at http://127.19.62.65:43027/ using document root <none> and password file <none>
I20260812 06:20:03.281345 19705 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:03.281404 19705 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:03.281482 19705 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:03.281903 19705 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/instance:
uuid: "cf2d9e0a5112461298cee57e09566986"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-zh2d"
I20260812 06:20:03.283471 19705 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:03.284516 19861 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.284765 19705 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:03.284874 19705 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root
uuid: "cf2d9e0a5112461298cee57e09566986"
format_stamp: "Formatted at 2026-08-12 06:20:03 on dist-test-slave-zh2d"
I20260812 06:20:03.284955 19705 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:03.292614 19705 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:03.293129 19705 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:03.293658 19705 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:03.294600 19705 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:03.294673 19705 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.294750 19705 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:03.294800 19705 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:03.301848 19705 rpc_server.cc:307] RPC server started. Bound to: 127.19.62.65:40681
I20260812 06:20:03.302151 19954 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.62.65:40681 every 8 connection(s)
I20260812 06:20:03.313053 19956 heartbeater.cc:344] Connected to a master server at 127.19.62.126:36351
I20260812 06:20:03.313311 19956 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:03.313763 19956 heartbeater.cc:507] Master 127.19.62.126:36351 requested a full tablet report, sending...
I20260812 06:20:03.315384 19752 ts_manager.cc:194] Registered new tserver with Master: cf2d9e0a5112461298cee57e09566986 (127.19.62.65:40681)
I20260812 06:20:03.316191 19705 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013502574s
I20260812 06:20:03.316934 19752 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44044
I20260812 06:20:03.325860 19752 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44056:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:03.340611 19908 tablet_service.cc:1511] Processing CreateTablet for tablet ae9238fb6c794755a44d540606d023f8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=b1f60cc784cc402881754bb7abcdf597]), partition=
I20260812 06:20:03.341185 19908 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ae9238fb6c794755a44d540606d023f8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:03.343842 19973 tablet_bootstrap.cc:492] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Bootstrap starting.
I20260812 06:20:03.345091 19973 tablet_bootstrap.cc:654] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:03.346410 19973 tablet_bootstrap.cc:492] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: No bootstrap required, opened a new log
I20260812 06:20:03.346530 19973 ts_tablet_manager.cc:1403] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:20:03.347009 19973 raft_consensus.cc:359] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cf2d9e0a5112461298cee57e09566986" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 40681 } }
I20260812 06:20:03.347127 19973 raft_consensus.cc:385] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:03.347162 19973 raft_consensus.cc:740] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cf2d9e0a5112461298cee57e09566986, State: Initialized, Role: FOLLOWER
I20260812 06:20:03.347348 19973 consensus_queue.cc:260] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [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: "cf2d9e0a5112461298cee57e09566986" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 40681 } }
I20260812 06:20:03.347469 19973 raft_consensus.cc:399] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:03.347534 19973 raft_consensus.cc:493] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:03.347597 19973 raft_consensus.cc:3060] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:03.348624 19973 raft_consensus.cc:515] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cf2d9e0a5112461298cee57e09566986" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 40681 } }
I20260812 06:20:03.348752 19973 leader_election.cc:304] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [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: cf2d9e0a5112461298cee57e09566986; no voters: 
I20260812 06:20:03.348995 19973 leader_election.cc:290] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:03.349133 19975 raft_consensus.cc:2804] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:03.349347 19975 raft_consensus.cc:697] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 1 LEADER]: Becoming Leader. State: Replica: cf2d9e0a5112461298cee57e09566986, State: Running, Role: LEADER
I20260812 06:20:03.349397 19973 ts_tablet_manager.cc:1434] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:03.349495 19975 consensus_queue.cc:237] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [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: "cf2d9e0a5112461298cee57e09566986" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 40681 } }
I20260812 06:20:03.349802 19956 heartbeater.cc:499] Master 127.19.62.126:36351 was elected leader, sending a full tablet report...
I20260812 06:20:03.353116 19752 catalog_manager.cc:5719] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 reported cstate change: term changed from 0 to 1, leader changed from <none> to cf2d9e0a5112461298cee57e09566986 (127.19.62.65). New cstate: current_term: 1 leader_uuid: "cf2d9e0a5112461298cee57e09566986" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cf2d9e0a5112461298cee57e09566986" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 40681 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:03.421754 19705 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.014s	sys 0.015s
I20260812 06:20:03.553431 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushMRSOp(ae9238fb6c794755a44d540606d023f8): perf score=15.086190
I20260812 06:20:03.725798 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushMRSOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.172s	user 0.126s	sys 0.033s Metrics: {"bytes_written":11897251,"cfile_init":1,"compiler_manager_pool.queue_time_us":226,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":869,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40958,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":102,"threads_started":1,"update_count":1450}
I20260812 06:20:03.727082 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling LogGCOp(ae9238fb6c794755a44d540606d023f8): free 20743880 bytes of WAL
I20260812 06:20:03.727418 19868 log_reader.cc:385] T ae9238fb6c794755a44d540606d023f8: removed 2 log segments from log reader
I20260812 06:20:03.727486 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000001 (ops 1-6)
I20260812 06:20:03.727540 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000002 (ops 7-11)
I20260812 06:20:03.733538 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: LogGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:20:03.733939 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8): 12719217 bytes on disk
I20260812 06:20:03.734666 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.735227 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:03.757728 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.022s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.758224 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:03.906646 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.148s	user 0.107s	sys 0.035s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262038,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":608,"lbm_read_time_us":8529,"lbm_reads_lt_1ms":450,"lbm_write_time_us":29981,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":432,"mutex_wait_us":65,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":12672,"thread_start_us":344,"threads_started":5,"update_count":1950}
I20260812 06:20:03.907425 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=11.118625
I20260812 06:20:03.941288 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.034s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15130,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:03.941867 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:03.957919 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5971,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:03.958391 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:04.104121 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.146s	user 0.101s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1583,"lbm_read_time_us":8775,"lbm_reads_lt_1ms":468,"lbm_write_time_us":31094,"lbm_writes_lt_1ms":443,"mutex_wait_us":608,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.104678 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=11.118625
I20260812 06:20:04.139724 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.035s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15477,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:04.140221 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:04.154946 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5421,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:04.155607 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:04.285005 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.129s	user 0.103s	sys 0.026s 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":818,"lbm_read_time_us":9994,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24921,"lbm_writes_lt_1ms":443,"mutex_wait_us":346,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:20:04.285637 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=10.126437
I20260812 06:20:04.335269 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.049s	user 0.013s	sys 0.028s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15583,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.335814 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:04.346817 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.347330 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:04.508785 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.161s	user 0.106s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":11321,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26423,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:20:04.509472 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=10.126437
I20260812 06:20:04.561483 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.052s	user 0.032s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17588,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.562016 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:04.573889 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.574537 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:04.717319 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.143s	user 0.107s	sys 0.036s 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":132,"lbm_read_time_us":11120,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28518,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:04.718163 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=10.126437
I20260812 06:20:04.765456 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.047s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18775,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.766000 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:04.777096 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.777946 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:04.913827 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.136s	user 0.107s	sys 0.028s 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":287,"lbm_read_time_us":10271,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28560,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:20:04.914512 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=10.126437
I20260812 06:20:04.968678 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.054s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15852,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.969269 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:04.980468 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4380,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.981038 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:05.155085 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.174s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":446,"lbm_read_time_us":12780,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29332,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:20:05.155851 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=10.126437
I20260812 06:20:05.196372 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.040s	user 0.012s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18408,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.197335 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:05.213096 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5913,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.213634 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushMRSOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:05.271566 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushMRSOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.058s	user 0.036s	sys 0.003s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1330,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1883,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:05.272536 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling LogGCOp(ae9238fb6c794755a44d540606d023f8): free 128867446 bytes of WAL
I20260812 06:20:05.272827 19868 log_reader.cc:385] T ae9238fb6c794755a44d540606d023f8: removed 13 log segments from log reader
I20260812 06:20:05.272918 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000003 (ops 12-16)
I20260812 06:20:05.272957 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000004 (ops 17-21)
I20260812 06:20:05.272989 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000005 (ops 22-26)
I20260812 06:20:05.273041 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000006 (ops 27-30)
I20260812 06:20:05.273077 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000007 (ops 31-35)
I20260812 06:20:05.273108 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000008 (ops 36-40)
I20260812 06:20:05.273138 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000009 (ops 41-45)
I20260812 06:20:05.273165 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000010 (ops 46-50)
I20260812 06:20:05.273196 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000011 (ops 51-54)
I20260812 06:20:05.273229 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000012 (ops 55-59)
I20260812 06:20:05.273262 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000013 (ops 60-64)
I20260812 06:20:05.273288 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000014 (ops 65-68)
I20260812 06:20:05.273348 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000015 (ops 69-73)
I20260812 06:20:05.306914 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: LogGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.034s	user 0.005s	sys 0.027s Metrics: {}
I20260812 06:20:05.307410 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=6.157687
I20260812 06:20:05.347121 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.039s	user 0.019s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":14269,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:05.347652 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8): 492 bytes on disk
I20260812 06:20:05.348101 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.348580 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:05.360368 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4675,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.360913 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:05.592144 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.231s	user 0.141s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2575,"lbm_read_time_us":17932,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40599,"lbm_writes_lt_1ms":743,"mutex_wait_us":1317,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11648,"thread_start_us":104,"threads_started":1,"update_count":3500}
I20260812 06:20:05.593007 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:05.638854 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20727,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.639485 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:05.658241 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.658787 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:05.862200 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.203s	user 0.150s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":15350,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36241,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:20:05.862814 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:05.930524 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.068s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.931272 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:05.942708 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4411,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.943161 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:06.141844 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.199s	user 0.131s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":174,"lbm_read_time_us":14964,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32726,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":64384,"update_count":2500}
I20260812 06:20:06.142513 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:06.207813 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.065s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.208326 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:06.220880 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.221537 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:06.408159 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.186s	user 0.123s	sys 0.060s 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":235,"lbm_read_time_us":14296,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30246,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:06.408782 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:06.475055 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.066s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18791,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.475673 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:06.486891 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.487354 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:06.688994 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.201s	user 0.127s	sys 0.060s 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":603,"lbm_read_time_us":13256,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32492,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:06.689802 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:06.741247 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.051s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20717,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.741770 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:06.757910 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.758615 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:06.965528 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.206s	user 0.145s	sys 0.059s 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":385,"lbm_read_time_us":14916,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34235,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:20:06.966401 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:07.033263 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.067s	user 0.054s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29176,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.034409 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:07.062139 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.027s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.062726 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:07.084151 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.021s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.084800 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushMRSOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:07.132699 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushMRSOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.048s	user 0.034s	sys 0.005s Metrics: {"bytes_written":1357578,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1364,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2026,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:20:07.133484 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling LogGCOp(ae9238fb6c794755a44d540606d023f8): free 133024403 bytes of WAL
I20260812 06:20:07.133739 19868 log_reader.cc:385] T ae9238fb6c794755a44d540606d023f8: removed 13 log segments from log reader
I20260812 06:20:07.133785 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000016 (ops 74-78)
I20260812 06:20:07.133838 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000017 (ops 79-83)
I20260812 06:20:07.133884 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000018 (ops 84-88)
I20260812 06:20:07.133925 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000019 (ops 89-93)
I20260812 06:20:07.133967 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000020 (ops 94-98)
I20260812 06:20:07.134008 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000021 (ops 99-103)
I20260812 06:20:07.134047 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000022 (ops 104-108)
I20260812 06:20:07.134084 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000023 (ops 109-112)
I20260812 06:20:07.134123 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000024 (ops 113-117)
I20260812 06:20:07.134166 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000025 (ops 118-122)
I20260812 06:20:07.134205 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000026 (ops 123-127)
I20260812 06:20:07.134245 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000027 (ops 128-132)
I20260812 06:20:07.134284 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000028 (ops 133-137)
I20260812 06:20:07.165452 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: LogGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.032s	user 0.004s	sys 0.027s Metrics: {}
I20260812 06:20:07.165846 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=3.181125
I20260812 06:20:07.189669 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.024s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7548,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:07.190114 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:07.199700 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3771,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.200106 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8): 508 bytes on disk
I20260812 06:20:07.200505 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:07.201056 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:07.475660 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.274s	user 0.198s	sys 0.067s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":671,"lbm_read_time_us":20411,"lbm_reads_lt_1ms":875,"lbm_write_time_us":48809,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":368,"threads_started":6,"update_count":4000}
I20260812 06:20:07.476447 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=18.063937
I20260812 06:20:07.540346 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.064s	user 0.036s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27486,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:07.540984 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:07.557530 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.016s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.558035 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:07.776635 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.218s	user 0.126s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1262,"lbm_read_time_us":15424,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38163,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":3000}
I20260812 06:20:07.777640 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=18.063937
I20260812 06:20:07.837888 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.060s	user 0.049s	sys 0.008s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26323,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:07.838462 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:07.855526 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.017s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.856092 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:08.052971 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.197s	user 0.155s	sys 0.042s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":16539,"lbm_reads_lt_1ms":664,"lbm_write_time_us":39239,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3000}
I20260812 06:20:08.053714 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:08.108717 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.055s	user 0.030s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24306,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.109277 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:08.125305 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.125869 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:08.301723 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.176s	user 0.116s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":12594,"lbm_reads_lt_1ms":568,"lbm_write_time_us":32162,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:08.302554 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:08.361662 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.059s	user 0.024s	sys 0.029s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24540,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.362193 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:08.524957 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.163s	user 0.093s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":238,"lbm_read_time_us":11290,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27689,"lbm_writes_lt_1ms":443,"mutex_wait_us":82,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.525753 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=14.095187
I20260812 06:20:08.577986 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.052s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21346,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.578540 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:08.591460 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.593180 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushMRSOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:08.631965 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushMRSOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.039s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":287,"dirs.run_wall_time_us":1393,"drs_written":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1579,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:08.632755 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling LogGCOp(ae9238fb6c794755a44d540606d023f8): free 121006697 bytes of WAL
I20260812 06:20:08.633073 19868 log_reader.cc:385] T ae9238fb6c794755a44d540606d023f8: removed 12 log segments from log reader
I20260812 06:20:08.633141 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000029 (ops 138-142)
I20260812 06:20:08.633183 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000030 (ops 143-146)
I20260812 06:20:08.633210 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000031 (ops 147-151)
I20260812 06:20:08.633237 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000032 (ops 152-156)
I20260812 06:20:08.633266 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000033 (ops 157-161)
I20260812 06:20:08.633293 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000034 (ops 162-166)
I20260812 06:20:08.633318 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000035 (ops 167-171)
I20260812 06:20:08.633366 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000036 (ops 172-176)
I20260812 06:20:08.633391 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000037 (ops 177-181)
I20260812 06:20:08.633416 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000038 (ops 182-186)
I20260812 06:20:08.633453 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000039 (ops 187-191)
I20260812 06:20:08.633490 19868 log.cc:1079] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/ae9238fb6c794755a44d540606d023f8/wal-000000040 (ops 192-196)
I20260812 06:20:08.671379 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: LogGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.038s	user 0.000s	sys 0.036s Metrics: {}
I20260812 06:20:08.671883 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8): 447 bytes on disk
I20260812 06:20:08.672590 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: UndoDeltaBlockGCOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.673281 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:08.700172 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.027s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.700639 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8): perf score=2.188937
I20260812 06:20:08.711560 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: FlushDeltaMemStoresOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.712010 19958 maintenance_manager.cc:419] P cf2d9e0a5112461298cee57e09566986: Scheduling MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8): perf score=1.000000
I20260812 06:20:08.748368 19705 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.326s	user 1.933s	sys 0.206s
I20260812 06:20:08.854667 19705 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.106s	user 0.002s	sys 0.000s
I20260812 06:20:08.855374 19705 tablet_server.cc:179] TabletServer@127.19.62.65:0 shutting down...
I20260812 06:20:08.914958 19868 maintenance_manager.cc:643] P cf2d9e0a5112461298cee57e09566986: MajorDeltaCompactionOp(ae9238fb6c794755a44d540606d023f8) complete. Timing: real 0.203s	user 0.129s	sys 0.073s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":527,"lbm_read_time_us":16734,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37034,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":23040,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:20:08.915794 19705 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:08.916268 19705 tablet_replica.cc:333] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986: stopping tablet replica
I20260812 06:20:08.916574 19705 raft_consensus.cc:2243] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.916887 19705 raft_consensus.cc:2272] T ae9238fb6c794755a44d540606d023f8 P cf2d9e0a5112461298cee57e09566986 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.934090 19705 tablet_server.cc:196] TabletServer@127.19.62.65:0 shutdown complete.
I20260812 06:20:08.975836 19705 master.cc:562] Master@127.19.62.126:36351 shutting down...
I20260812 06:20:08.980684 19705 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:08.980926 19705 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:08.981014 19705 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7c273aa702644f03bece77cbbd87875a: stopping tablet replica
I20260812 06:20:08.993571 19705 master.cc:584] Master@127.19.62.126:36351 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5959 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:09.101514 19705 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.19.62.126:44785
I20260812 06:20:09.101917 19705 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.104120 20024 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.104275 20023 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.104308 20027 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.104395 19705 server_base.cc:1061] running on GCE node
I20260812 06:20:09.104660 19705 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.104727 19705 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:09.104754 19705 hybrid_clock.cc:648] HybridClock initialized: now 1786515609104753 us; error 0 us; skew 500 ppm
I20260812 06:20:09.105660 19705 webserver.cc:533] Webserver started at http://127.19.62.126:37471/ using document root <none> and password file <none>
I20260812 06:20:09.105859 19705 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.105945 19705 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.106029 19705 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.106454 19705 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/master-0-root/instance:
uuid: "515be2812e1344548e75b9432e5fba68"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-zh2d"
I20260812 06:20:09.107996 19705 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:09.108997 20034 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.109295 19705 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:09.109390 19705 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/master-0-root
uuid: "515be2812e1344548e75b9432e5fba68"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-zh2d"
I20260812 06:20:09.109476 19705 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:09.140010 19705 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.140450 19705 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.145147 19705 rpc_server.cc:307] RPC server started. Bound to: 127.19.62.126:44785
I20260812 06:20:09.147902 20119 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.62.126:44785 every 8 connection(s)
I20260812 06:20:09.153582 20120 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.155438 20120 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68: Bootstrap starting.
I20260812 06:20:09.156263 20120 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.157325 20120 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68: No bootstrap required, opened a new log
I20260812 06:20:09.157742 20120 raft_consensus.cc:359] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "515be2812e1344548e75b9432e5fba68" member_type: VOTER }
I20260812 06:20:09.157830 20120 raft_consensus.cc:385] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.157893 20120 raft_consensus.cc:740] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 515be2812e1344548e75b9432e5fba68, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.158077 20120 consensus_queue.cc:260] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [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: "515be2812e1344548e75b9432e5fba68" member_type: VOTER }
I20260812 06:20:09.158154 20120 raft_consensus.cc:399] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.158219 20120 raft_consensus.cc:493] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.158301 20120 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.159077 20120 raft_consensus.cc:515] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "515be2812e1344548e75b9432e5fba68" member_type: VOTER }
I20260812 06:20:09.159233 20120 leader_election.cc:304] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [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: 515be2812e1344548e75b9432e5fba68; no voters: 
I20260812 06:20:09.159447 20120 leader_election.cc:290] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.159579 20128 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.159803 20128 raft_consensus.cc:697] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 1 LEADER]: Becoming Leader. State: Replica: 515be2812e1344548e75b9432e5fba68, State: Running, Role: LEADER
I20260812 06:20:09.159901 20120 sys_catalog.cc:565] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:09.159994 20128 consensus_queue.cc:237] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [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: "515be2812e1344548e75b9432e5fba68" member_type: VOTER }
I20260812 06:20:09.160449 20129 sys_catalog.cc:455] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "515be2812e1344548e75b9432e5fba68" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "515be2812e1344548e75b9432e5fba68" member_type: VOTER } }
I20260812 06:20:09.160564 20129 sys_catalog.cc:458] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.160461 20130 sys_catalog.cc:455] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 515be2812e1344548e75b9432e5fba68. Latest consensus state: current_term: 1 leader_uuid: "515be2812e1344548e75b9432e5fba68" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "515be2812e1344548e75b9432e5fba68" member_type: VOTER } }
I20260812 06:20:09.160777 20130 sys_catalog.cc:458] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:09.160881 20137 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:09.161620 20137 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:09.161959 19705 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:09.163525 20137 catalog_manager.cc:1383] Generated new cluster ID: 0390d55b4b0045aa8b3c1bb6dad515e3
I20260812 06:20:09.163581 20137 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:09.171654 20137 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:09.172158 20137 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:09.182149 20137 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68: Generated new TSK 0
I20260812 06:20:09.182307 20137 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:09.194247 19705 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:09.196341 20161 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.196485 19705 server_base.cc:1061] running on GCE node
W20260812 06:20:09.196401 20164 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:09.196362 20162 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:09.196791 19705 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:09.196880 19705 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:09.196918 19705 hybrid_clock.cc:648] HybridClock initialized: now 1786515609196917 us; error 0 us; skew 500 ppm
I20260812 06:20:09.197805 19705 webserver.cc:533] Webserver started at http://127.19.62.65:40849/ using document root <none> and password file <none>
I20260812 06:20:09.197985 19705 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:09.198061 19705 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:09.198149 19705 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:09.198570 19705 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/instance:
uuid: "a053762f0ed24b40a217ecf7c1076374"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-zh2d"
I20260812 06:20:09.200101 19705 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:09.201099 20170 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.201336 19705 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:09.201426 19705 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root
uuid: "a053762f0ed24b40a217ecf7c1076374"
format_stamp: "Formatted at 2026-08-12 06:20:09 on dist-test-slave-zh2d"
I20260812 06:20:09.201521 19705 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:09.255206 19705 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:09.255712 19705 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:09.256171 19705 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:09.256868 19705 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:09.256918 19705 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.257010 19705 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:09.257045 19705 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:09.262876 19705 rpc_server.cc:307] RPC server started. Bound to: 127.19.62.65:33971
I20260812 06:20:09.262913 20271 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.19.62.65:33971 every 8 connection(s)
I20260812 06:20:09.268115 20273 heartbeater.cc:344] Connected to a master server at 127.19.62.126:44785
I20260812 06:20:09.268234 20273 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:09.268467 20273 heartbeater.cc:507] Master 127.19.62.126:44785 requested a full tablet report, sending...
I20260812 06:20:09.269168 20064 ts_manager.cc:194] Registered new tserver with Master: a053762f0ed24b40a217ecf7c1076374 (127.19.62.65:33971)
I20260812 06:20:09.269845 20064 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35558
I20260812 06:20:09.269923 19705 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006615252s
I20260812 06:20:09.276893 20064 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35574:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:09.286000 20212 tablet_service.cc:1511] Processing CreateTablet for tablet 77e557b8c6794d7385bea9f8374d20fc (DEFAULT_TABLE table=heavy-update-compaction-test [id=dc63d5cfea214cbe9ca6c44c6898c252]), partition=
I20260812 06:20:09.286288 20212 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 77e557b8c6794d7385bea9f8374d20fc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:09.288569 20292 tablet_bootstrap.cc:492] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Bootstrap starting.
I20260812 06:20:09.289523 20292 tablet_bootstrap.cc:654] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:09.290617 20292 tablet_bootstrap.cc:492] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: No bootstrap required, opened a new log
I20260812 06:20:09.290714 20292 ts_tablet_manager.cc:1403] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:09.291287 20292 raft_consensus.cc:359] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a053762f0ed24b40a217ecf7c1076374" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 33971 } }
I20260812 06:20:09.291391 20292 raft_consensus.cc:385] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:09.291433 20292 raft_consensus.cc:740] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a053762f0ed24b40a217ecf7c1076374, State: Initialized, Role: FOLLOWER
I20260812 06:20:09.291587 20292 consensus_queue.cc:260] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [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: "a053762f0ed24b40a217ecf7c1076374" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 33971 } }
I20260812 06:20:09.291682 20292 raft_consensus.cc:399] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:09.291746 20292 raft_consensus.cc:493] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:09.291805 20292 raft_consensus.cc:3060] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:09.292557 20292 raft_consensus.cc:515] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a053762f0ed24b40a217ecf7c1076374" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 33971 } }
I20260812 06:20:09.292721 20292 leader_election.cc:304] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [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: a053762f0ed24b40a217ecf7c1076374; no voters: 
I20260812 06:20:09.292971 20292 leader_election.cc:290] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:09.293120 20294 raft_consensus.cc:2804] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:09.293351 20292 ts_tablet_manager.cc:1434] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:09.293409 20273 heartbeater.cc:499] Master 127.19.62.126:44785 was elected leader, sending a full tablet report...
I20260812 06:20:09.293361 20294 raft_consensus.cc:697] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 1 LEADER]: Becoming Leader. State: Replica: a053762f0ed24b40a217ecf7c1076374, State: Running, Role: LEADER
I20260812 06:20:09.293552 20294 consensus_queue.cc:237] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [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: "a053762f0ed24b40a217ecf7c1076374" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 33971 } }
I20260812 06:20:09.294927 20064 catalog_manager.cc:5719] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 reported cstate change: term changed from 0 to 1, leader changed from <none> to a053762f0ed24b40a217ecf7c1076374 (127.19.62.65). New cstate: current_term: 1 leader_uuid: "a053762f0ed24b40a217ecf7c1076374" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a053762f0ed24b40a217ecf7c1076374" member_type: VOTER last_known_addr { host: "127.19.62.65" port: 33971 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:09.357097 19705 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.011s	sys 0.012s
I20260812 06:20:09.513856 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc): perf score=19.054940
I20260812 06:20:09.683482 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.169s	user 0.126s	sys 0.040s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":966,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":911,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42303,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:20:09.684201 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling LogGCOp(77e557b8c6794d7385bea9f8374d20fc): free 20743880 bytes of WAL
I20260812 06:20:09.684479 20179 log_reader.cc:385] T 77e557b8c6794d7385bea9f8374d20fc: removed 2 log segments from log reader
I20260812 06:20:09.684526 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000001 (ops 1-6)
I20260812 06:20:09.684561 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000002 (ops 7-11)
I20260812 06:20:09.689532 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: LogGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:09.689985 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc): 16411396 bytes on disk
I20260812 06:20:09.690481 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.690904 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:09.705439 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5195,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.705921 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:09.853490 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.147s	user 0.084s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":12484,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25217,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":351,"threads_started":5,"update_count":2000}
I20260812 06:20:09.854209 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:09.906061 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.052s	user 0.031s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19046,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:09.906566 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:09.918588 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.919096 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:10.089833 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.171s	user 0.119s	sys 0.051s 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":926,"lbm_read_time_us":13964,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28628,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17792,"update_count":2000}
I20260812 06:20:10.090528 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:10.136178 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.045s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20193,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.136765 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:10.149101 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.149576 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:10.289539 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.140s	user 0.122s	sys 0.017s 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":1024,"lbm_read_time_us":11869,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25648,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2000}
I20260812 06:20:10.290256 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:10.338732 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.048s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18298,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.339226 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:10.351121 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.351621 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:10.491184 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.139s	user 0.102s	sys 0.035s 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":226,"lbm_read_time_us":11275,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26913,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:20:10.491871 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:10.537758 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.046s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16143,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.538300 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:10.550122 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.550617 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:10.681402 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.131s	user 0.093s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":9342,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27515,"lbm_writes_lt_1ms":443,"mutex_wait_us":113,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:10.682215 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:10.732187 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.050s	user 0.019s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18069,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.732897 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:10.744194 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4452,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.744676 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:10.911170 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.166s	user 0.090s	sys 0.077s 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":312,"lbm_read_time_us":13906,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27699,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21248,"update_count":2000}
I20260812 06:20:10.911926 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:10.952432 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17771,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.953115 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:10.966424 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4551,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:10.966886 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:10.993614 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.027s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1316,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1796,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:10.994240 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling LogGCOp(77e557b8c6794d7385bea9f8374d20fc): free 112692367 bytes of WAL
I20260812 06:20:10.994505 20179 log_reader.cc:385] T 77e557b8c6794d7385bea9f8374d20fc: removed 11 log segments from log reader
I20260812 06:20:10.994550 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000003 (ops 12-16)
I20260812 06:20:10.994581 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000004 (ops 17-21)
I20260812 06:20:10.994647 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000005 (ops 22-26)
I20260812 06:20:10.994690 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000006 (ops 27-31)
I20260812 06:20:10.994735 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000007 (ops 32-36)
I20260812 06:20:10.994793 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000008 (ops 37-41)
I20260812 06:20:10.994833 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000009 (ops 42-46)
I20260812 06:20:10.994880 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000010 (ops 47-51)
I20260812 06:20:10.994923 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000011 (ops 52-56)
I20260812 06:20:10.994964 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000012 (ops 57-61)
I20260812 06:20:10.995002 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000013 (ops 62-66)
I20260812 06:20:11.019754 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: LogGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:11.020201 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:11.046223 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.026s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.046716 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc): 447 bytes on disk
I20260812 06:20:11.047155 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.047607 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:11.058460 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.058903 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:11.267540 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.208s	user 0.125s	sys 0.083s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":563,"lbm_read_time_us":15843,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36248,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":104,"threads_started":1,"update_count":3000}
I20260812 06:20:11.268265 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:11.340608 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.072s	user 0.028s	sys 0.038s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26042,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.341207 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:11.360216 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.360816 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:11.577400 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.216s	user 0.130s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":427,"lbm_read_time_us":16686,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36941,"lbm_writes_lt_1ms":543,"mutex_wait_us":74,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:20:11.578132 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:11.633399 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.055s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20453,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.633948 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:11.656229 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.022s	user 0.003s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.656883 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:11.848274 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.191s	user 0.126s	sys 0.065s 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":239,"lbm_read_time_us":14379,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31072,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:20:11.848955 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:11.897833 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.049s	user 0.033s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20343,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:11.898341 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:11.914991 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6134,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.916313 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:12.103772 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.187s	user 0.132s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":13649,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30392,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20608,"update_count":2500}
I20260812 06:20:12.104535 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:12.154980 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.050s	user 0.021s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22246,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.155463 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:12.167666 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4485,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.168145 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:12.328262 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.160s	user 0.129s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":11975,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30990,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:12.329020 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=11.118625
I20260812 06:20:12.381296 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.052s	user 0.022s	sys 0.025s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":21291,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.381827 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:12.393278 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.393754 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:12.407642 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5267,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.408217 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:12.573817 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.165s	user 0.138s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":128,"lbm_read_time_us":13256,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32600,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:20:12.574589 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:12.609843 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.033s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12594659,"delete_count":0,"lbm_write_time_us":14794,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:20:12.610512 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:12.620893 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3962,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:12.621348 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:12.660007 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.038s	user 0.029s	sys 0.008s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1448,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2302,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:12.660964 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling LogGCOp(77e557b8c6794d7385bea9f8374d20fc): free 132571318 bytes of WAL
I20260812 06:20:12.661186 20179 log_reader.cc:385] T 77e557b8c6794d7385bea9f8374d20fc: removed 13 log segments from log reader
I20260812 06:20:12.661231 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000014 (ops 67-70)
I20260812 06:20:12.661278 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000015 (ops 71-75)
I20260812 06:20:12.661321 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000016 (ops 76-80)
I20260812 06:20:12.661362 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000017 (ops 81-85)
I20260812 06:20:12.661406 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000018 (ops 86-90)
I20260812 06:20:12.661468 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000019 (ops 91-94)
I20260812 06:20:12.661521 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000020 (ops 95-99)
I20260812 06:20:12.661556 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000021 (ops 100-104)
I20260812 06:20:12.661593 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000022 (ops 105-109)
I20260812 06:20:12.661631 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000023 (ops 110-114)
I20260812 06:20:12.661669 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000024 (ops 115-119)
I20260812 06:20:12.661708 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000025 (ops 120-124)
I20260812 06:20:12.661748 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000026 (ops 125-129)
I20260812 06:20:12.693607 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: LogGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.032s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:20:12.694130 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=4.173312
I20260812 06:20:12.708297 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":5941,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:20:12.708750 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.196750
I20260812 06:20:12.718271 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3035,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:20:12.718955 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc): 482 bytes on disk
I20260812 06:20:12.719515 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.720039 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:12.909111 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.189s	user 0.124s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877307,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":292,"lbm_read_time_us":14038,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40504,"lbm_writes_lt_1ms":643,"mutex_wait_us":67,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:20:12.909709 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:12.957192 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.047s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21253,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:12.957857 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:12.970753 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.971334 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:13.140579 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.169s	user 0.109s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":759,"lbm_read_time_us":12252,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31378,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":85248,"update_count":2500}
I20260812 06:20:13.141474 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:13.207387 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.066s	user 0.030s	sys 0.022s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":24981,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.207906 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:13.220353 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.220981 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:13.404233 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.183s	user 0.130s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":13889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31443,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":51584,"update_count":2500}
I20260812 06:20:13.404914 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:13.469352 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.061s	user 0.041s	sys 0.020s Metrics: {"bytes_written":16409938,"delete_count":0,"lbm_write_time_us":26945,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.469928 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:13.482390 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4791,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.482919 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:13.668493 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.185s	user 0.125s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":722,"lbm_read_time_us":15229,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32343,"lbm_writes_lt_1ms":543,"mutex_wait_us":404,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:13.669077 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:13.737192 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.068s	user 0.031s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23577,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.737820 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:13.755716 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6745,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.756382 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:13.977908 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.221s	user 0.132s	sys 0.079s 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":170,"lbm_read_time_us":15837,"lbm_reads_lt_1ms":572,"lbm_write_time_us":40779,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:13.978648 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=14.095187
I20260812 06:20:14.042127 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.063s	user 0.027s	sys 0.035s Metrics: {"bytes_written":16409934,"delete_count":0,"lbm_write_time_us":23302,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.042953 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:14.055447 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4952,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.055936 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:14.268576 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.212s	user 0.130s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":788,"lbm_read_time_us":16822,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35246,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:20:14.269361 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=11.118625
I20260812 06:20:14.314888 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":18323,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:14.315430 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:14.326517 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.326994 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:14.336676 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:14.337167 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:14.384812 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushMRSOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.047s	user 0.039s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1411,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1876,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:14.385756 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling LogGCOp(77e557b8c6794d7385bea9f8374d20fc): free 133024654 bytes of WAL
I20260812 06:20:14.386057 20179 log_reader.cc:385] T 77e557b8c6794d7385bea9f8374d20fc: removed 13 log segments from log reader
I20260812 06:20:14.386128 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000027 (ops 130-134)
I20260812 06:20:14.386171 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000028 (ops 135-139)
I20260812 06:20:14.386205 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000029 (ops 140-144)
I20260812 06:20:14.386229 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000030 (ops 145-149)
I20260812 06:20:14.386260 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000031 (ops 150-154)
I20260812 06:20:14.386292 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000032 (ops 155-159)
I20260812 06:20:14.386327 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000033 (ops 160-164)
I20260812 06:20:14.386358 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000034 (ops 165-169)
I20260812 06:20:14.386385 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000035 (ops 170-174)
I20260812 06:20:14.386407 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000036 (ops 175-179)
I20260812 06:20:14.386436 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000037 (ops 180-184)
I20260812 06:20:14.386462 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000038 (ops 185-188)
I20260812 06:20:14.386488 20179 log.cc:1079] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: Deleting log segment in path: /tmp/dist-test-taskMQ88ab/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515603116604-19705-0/minicluster-data/ts-0-root/wals/77e557b8c6794d7385bea9f8374d20fc/wal-000000039 (ops 189-193)
I20260812 06:20:14.420675 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: LogGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.035s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:14.421149 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc): 493 bytes on disk
I20260812 06:20:14.421782 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: UndoDeltaBlockGCOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.422451 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:14.444453 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.022s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.445050 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=2.188937
I20260812 06:20:14.455878 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4190,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.456326 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc): perf score=1.000000
I20260812 06:20:14.591060 19705 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.234s	user 1.930s	sys 0.193s
I20260812 06:20:14.687198 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: MajorDeltaCompactionOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.230s	user 0.141s	sys 0.089s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979864,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":160,"lbm_read_time_us":17894,"lbm_reads_lt_1ms":771,"lbm_write_time_us":37689,"lbm_writes_lt_1ms":743,"mutex_wait_us":43,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:20:14.688232 20274 maintenance_manager.cc:419] P a053762f0ed24b40a217ecf7c1076374: Scheduling FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc): perf score=10.126437
I20260812 06:20:14.698590 19705 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.107s	user 0.003s	sys 0.000s
I20260812 06:20:14.699246 19705 tablet_server.cc:179] TabletServer@127.19.62.65:0 shutting down...
I20260812 06:20:14.732379 20179 maintenance_manager.cc:643] P a053762f0ed24b40a217ecf7c1076374: FlushDeltaMemStoresOp(77e557b8c6794d7385bea9f8374d20fc) complete. Timing: real 0.044s	user 0.036s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19849,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.733067 19705 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:14.733295 19705 tablet_replica.cc:333] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374: stopping tablet replica
I20260812 06:20:14.733469 19705 raft_consensus.cc:2243] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.733665 19705 raft_consensus.cc:2272] T 77e557b8c6794d7385bea9f8374d20fc P a053762f0ed24b40a217ecf7c1076374 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.737251 19705 tablet_server.cc:196] TabletServer@127.19.62.65:0 shutdown complete.
I20260812 06:20:14.745544 19705 master.cc:562] Master@127.19.62.126:44785 shutting down...
I20260812 06:20:14.749114 19705 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:14.749303 19705 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:14.749395 19705 tablet_replica.cc:333] T 00000000000000000000000000000000 P 515be2812e1344548e75b9432e5fba68: stopping tablet replica
I20260812 06:20:14.761698 19705 master.cc:584] Master@127.19.62.126:44785 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5769 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11730 ms total)

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