[==========] 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:28.565191  3389 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.79.126:36669
I20260812 06:20:28.566213  3389 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:28.566852  3389 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:28.573370  3400 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:28.573498  3396 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:28.573630  3394 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:28.573647  3389 server_base.cc:1061] running on GCE node
I20260812 06:20:28.574198  3389 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:28.574322  3389 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:28.574373  3389 hybrid_clock.cc:648] HybridClock initialized: now 1786515628574370 us; error 0 us; skew 500 ppm
I20260812 06:20:28.576210  3389 webserver.cc:533] Webserver started at http://127.3.79.126:43201/ using document root <none> and password file <none>
I20260812 06:20:28.576839  3389 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:28.576901  3389 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:28.577147  3389 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:28.578783  3389 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/master-0-root/instance:
uuid: "1d4f9616bc1c4ccab12f468634cd9e59"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-g170"
I20260812 06:20:28.582106  3389 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:28.584079  3408 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:28.585161  3389 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:28.585290  3389 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/master-0-root
uuid: "1d4f9616bc1c4ccab12f468634cd9e59"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-g170"
I20260812 06:20:28.585397  3389 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-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:28.605742  3389 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:28.606395  3389 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:28.606578  3389 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:28.614596  3389 rpc_server.cc:307] RPC server started. Bound to: 127.3.79.126:36669
I20260812 06:20:28.614615  3492 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.79.126:36669 every 8 connection(s)
I20260812 06:20:28.616986  3494 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:28.622256  3494 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59: Bootstrap starting.
I20260812 06:20:28.624585  3494 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:28.625541  3494 log.cc:826] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:28.627225  3494 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59: No bootstrap required, opened a new log
I20260812 06:20:28.630101  3494 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d4f9616bc1c4ccab12f468634cd9e59" member_type: VOTER }
I20260812 06:20:28.630275  3494 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:28.630371  3494 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1d4f9616bc1c4ccab12f468634cd9e59, State: Initialized, Role: FOLLOWER
I20260812 06:20:28.631047  3494 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [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: "1d4f9616bc1c4ccab12f468634cd9e59" member_type: VOTER }
I20260812 06:20:28.631212  3494 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:28.631297  3494 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:28.631462  3494 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:28.632247  3494 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d4f9616bc1c4ccab12f468634cd9e59" member_type: VOTER }
I20260812 06:20:28.632686  3494 leader_election.cc:304] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [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: 1d4f9616bc1c4ccab12f468634cd9e59; no voters: 
I20260812 06:20:28.633014  3494 leader_election.cc:290] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:28.633143  3500 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:28.633406  3500 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 1 LEADER]: Becoming Leader. State: Replica: 1d4f9616bc1c4ccab12f468634cd9e59, State: Running, Role: LEADER
I20260812 06:20:28.633885  3500 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [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: "1d4f9616bc1c4ccab12f468634cd9e59" member_type: VOTER }
I20260812 06:20:28.633972  3494 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:28.635797  3502 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1d4f9616bc1c4ccab12f468634cd9e59. Latest consensus state: current_term: 1 leader_uuid: "1d4f9616bc1c4ccab12f468634cd9e59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d4f9616bc1c4ccab12f468634cd9e59" member_type: VOTER } }
I20260812 06:20:28.635839  3501 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1d4f9616bc1c4ccab12f468634cd9e59" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d4f9616bc1c4ccab12f468634cd9e59" member_type: VOTER } }
I20260812 06:20:28.635937  3502 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:28.635936  3501 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:28.636279  3521 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:28.636456  3389 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:28.638475  3521 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:28.642664  3521 catalog_manager.cc:1383] Generated new cluster ID: 14f8ec68424145f7adcc94ac2a98986c
I20260812 06:20:28.642727  3521 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:28.648658  3521 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:28.649785  3521 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:28.663002  3521 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59: Generated new TSK 0
I20260812 06:20:28.663678  3521 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:28.669507  3389 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:28.672142  3531 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:28.672230  3530 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:28.672246  3541 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:28.672863  3389 server_base.cc:1061] running on GCE node
I20260812 06:20:28.673050  3389 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:28.673099  3389 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:28.673147  3389 hybrid_clock.cc:648] HybridClock initialized: now 1786515628673146 us; error 0 us; skew 500 ppm
I20260812 06:20:28.674185  3389 webserver.cc:533] Webserver started at http://127.3.79.65:38963/ using document root <none> and password file <none>
I20260812 06:20:28.674358  3389 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:28.674417  3389 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:28.674521  3389 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:28.674924  3389 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/instance:
uuid: "952f0338c6724715b31003c9bbc45f9c"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-g170"
I20260812 06:20:28.676483  3389 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:28.677628  3552 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:28.677883  3389 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:28.677956  3389 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root
uuid: "952f0338c6724715b31003c9bbc45f9c"
format_stamp: "Formatted at 2026-08-12 06:20:28 on dist-test-slave-g170"
I20260812 06:20:28.678045  3389 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-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:28.684903  3389 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:28.685318  3389 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:28.685817  3389 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:28.686684  3389 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:28.686736  3389 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:28.686776  3389 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:28.686848  3389 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:28.694000  3389 rpc_server.cc:307] RPC server started. Bound to: 127.3.79.65:40451
I20260812 06:20:28.694063  3653 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.79.65:40451 every 8 connection(s)
I20260812 06:20:28.706560  3655 heartbeater.cc:344] Connected to a master server at 127.3.79.126:36669
I20260812 06:20:28.706820  3655 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:28.707249  3655 heartbeater.cc:507] Master 127.3.79.126:36669 requested a full tablet report, sending...
I20260812 06:20:28.708666  3433 ts_manager.cc:194] Registered new tserver with Master: 952f0338c6724715b31003c9bbc45f9c (127.3.79.65:40451)
I20260812 06:20:28.709206  3389 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014569528s
I20260812 06:20:28.710208  3433 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37412
I20260812 06:20:28.719339  3433 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37424:
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:28.733493  3594 tablet_service.cc:1511] Processing CreateTablet for tablet 7edf3c82ed0a4c0dadbd851d26f1a6b1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d36296c34406478dbf5377327c362e12]), partition=
I20260812 06:20:28.733955  3594 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7edf3c82ed0a4c0dadbd851d26f1a6b1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:28.736848  3675 tablet_bootstrap.cc:492] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Bootstrap starting.
I20260812 06:20:28.737746  3675 tablet_bootstrap.cc:654] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:28.738874  3675 tablet_bootstrap.cc:492] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: No bootstrap required, opened a new log
I20260812 06:20:28.738987  3675 ts_tablet_manager.cc:1403] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:28.739461  3675 raft_consensus.cc:359] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "952f0338c6724715b31003c9bbc45f9c" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 40451 } }
I20260812 06:20:28.739573  3675 raft_consensus.cc:385] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:28.739616  3675 raft_consensus.cc:740] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 952f0338c6724715b31003c9bbc45f9c, State: Initialized, Role: FOLLOWER
I20260812 06:20:28.739782  3675 consensus_queue.cc:260] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [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: "952f0338c6724715b31003c9bbc45f9c" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 40451 } }
I20260812 06:20:28.739866  3675 raft_consensus.cc:399] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:28.739912  3675 raft_consensus.cc:493] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:28.739974  3675 raft_consensus.cc:3060] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:28.740980  3675 raft_consensus.cc:515] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "952f0338c6724715b31003c9bbc45f9c" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 40451 } }
I20260812 06:20:28.741138  3675 leader_election.cc:304] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [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: 952f0338c6724715b31003c9bbc45f9c; no voters: 
I20260812 06:20:28.741370  3675 leader_election.cc:290] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:28.741469  3677 raft_consensus.cc:2804] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:28.741658  3677 raft_consensus.cc:697] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 1 LEADER]: Becoming Leader. State: Replica: 952f0338c6724715b31003c9bbc45f9c, State: Running, Role: LEADER
I20260812 06:20:28.741772  3675 ts_tablet_manager.cc:1434] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:28.741868  3677 consensus_queue.cc:237] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [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: "952f0338c6724715b31003c9bbc45f9c" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 40451 } }
I20260812 06:20:28.741950  3655 heartbeater.cc:499] Master 127.3.79.126:36669 was elected leader, sending a full tablet report...
I20260812 06:20:28.744998  3433 catalog_manager.cc:5719] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c reported cstate change: term changed from 0 to 1, leader changed from <none> to 952f0338c6724715b31003c9bbc45f9c (127.3.79.65). New cstate: current_term: 1 leader_uuid: "952f0338c6724715b31003c9bbc45f9c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "952f0338c6724715b31003c9bbc45f9c" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 40451 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:28.811503  3389 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.017s	sys 0.008s
I20260812 06:20:28.945264  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=15.086190
I20260812 06:20:29.109198  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.164s	user 0.129s	sys 0.032s Metrics: {"bytes_written":13866396,"cfile_init":1,"compiler_manager_pool.queue_time_us":214,"delete_count":0,"dirs.queue_time_us":1329,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":821,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42947,"lbm_writes_lt_1ms":705,"mutex_wait_us":161,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":146176,"thread_start_us":146,"threads_started":1,"update_count":1690}
I20260812 06:20:29.110440  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): 12719214 bytes on disk
I20260812 06:20:29.111106  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.111482  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:29.121596  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3815488,"delete_count":0,"lbm_write_time_us":3769,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:29.122056  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): free 20743880 bytes of WAL
I20260812 06:20:29.122336  3559 log_reader.cc:385] T 7edf3c82ed0a4c0dadbd851d26f1a6b1: removed 2 log segments from log reader
I20260812 06:20:29.122421  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000001 (ops 1-6)
I20260812 06:20:29.122498  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000002 (ops 7-11)
I20260812 06:20:29.128409  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:29.128724  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.196750
I20260812 06:20:29.138506  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":2420629,"delete_count":0,"lbm_write_time_us":3434,"lbm_writes_lt_1ms":62,"reinsert_count":0,"update_count":295}
I20260812 06:20:29.138923  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:29.313930  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.175s	user 0.131s	sys 0.040s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364513,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1015,"lbm_read_time_us":11573,"lbm_reads_lt_1ms":559,"lbm_write_time_us":29141,"lbm_writes_lt_1ms":533,"mutex_wait_us":37,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":7808,"thread_start_us":344,"threads_started":5,"update_count":2450}
I20260812 06:20:29.314482  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:29.361096  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.046s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16394,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.361538  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:29.374080  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4552,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.374533  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:29.499641  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":8139,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26227,"lbm_writes_lt_1ms":443,"mutex_wait_us":59,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":32000,"update_count":2000}
I20260812 06:20:29.500257  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:29.545905  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.045s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18840,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.546411  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:29.557158  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.557884  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:29.689180  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.131s	user 0.114s	sys 0.016s 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":1533,"lbm_read_time_us":10157,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24922,"lbm_writes_lt_1ms":443,"mutex_wait_us":400,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:20:29.689667  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:29.746462  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.057s	user 0.028s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19251,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.747063  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:29.759078  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.759545  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:29.913460  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.154s	user 0.092s	sys 0.060s 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":1720,"lbm_read_time_us":11422,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25919,"lbm_writes_lt_1ms":443,"mutex_wait_us":983,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:20:29.914748  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:29.956861  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.042s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18705,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.957408  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:29.970336  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.970909  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:30.104202  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.133s	user 0.096s	sys 0.037s 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":642,"lbm_read_time_us":9590,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26950,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:30.104918  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:30.142433  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.037s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16085,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.143240  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:30.158612  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.159214  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:30.271965  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.113s	user 0.088s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":459,"lbm_read_time_us":8288,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22516,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:30.272471  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:30.319727  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.047s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16684,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.320278  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:30.335716  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5880,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.336313  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:30.363435  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1576,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1519,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:30.364215  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): free 115943204 bytes of WAL
I20260812 06:20:30.364440  3559 log_reader.cc:385] T 7edf3c82ed0a4c0dadbd851d26f1a6b1: removed 11 log segments from log reader
I20260812 06:20:30.364487  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000003 (ops 12-16)
I20260812 06:20:30.364516  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000004 (ops 17-21)
I20260812 06:20:30.364575  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000005 (ops 22-26)
I20260812 06:20:30.364619  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000006 (ops 27-31)
I20260812 06:20:30.364681  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000007 (ops 32-36)
I20260812 06:20:30.364724  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000008 (ops 37-41)
I20260812 06:20:30.364786  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000009 (ops 42-46)
I20260812 06:20:30.364823  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000010 (ops 47-51)
I20260812 06:20:30.364856  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000011 (ops 52-56)
I20260812 06:20:30.364893  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000012 (ops 57-61)
I20260812 06:20:30.364931  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000013 (ops 62-66)
I20260812 06:20:30.391983  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:30.392390  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=3.181125
I20260812 06:20:30.406617  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4465,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:30.407111  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:30.417569  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.010s	user 0.007s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.418012  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): 447 bytes on disk
I20260812 06:20:30.418453  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.418867  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:30.598829  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.180s	user 0.124s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":206,"lbm_read_time_us":12925,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37404,"lbm_writes_lt_1ms":643,"mutex_wait_us":84,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:20:30.599344  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=14.095187
I20260812 06:20:30.664420  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.065s	user 0.037s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26440,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.664978  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:30.676553  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.677356  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:30.853140  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.176s	user 0.142s	sys 0.032s 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":515,"lbm_read_time_us":13355,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33181,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:30.853885  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=14.095187
I20260812 06:20:30.914213  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.060s	user 0.043s	sys 0.016s Metrics: {"bytes_written":16409931,"delete_count":0,"lbm_write_time_us":26353,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.914980  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:31.060606  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.145s	user 0.097s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672187,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":138,"lbm_read_time_us":9547,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26130,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:20:31.061779  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:31.097635  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.035s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15302,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":541440,"update_count":1500}
I20260812 06:20:31.098181  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.114588  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.115181  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:31.241194  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.126s	user 0.089s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":474,"lbm_read_time_us":8105,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23482,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.241850  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=11.118625
I20260812 06:20:31.280305  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.038s	user 0.016s	sys 0.018s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14095,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:31.280983  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.303877  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.023s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6088,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.304325  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.314621  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3999,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.315099  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:31.471223  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.156s	user 0.115s	sys 0.040s 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":1082,"lbm_read_time_us":11715,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32111,"lbm_writes_lt_1ms":543,"mutex_wait_us":702,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:20:31.472030  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:31.518471  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.046s	user 0.013s	sys 0.032s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20932,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.518993  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.531430  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.531865  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:31.665800  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.134s	user 0.106s	sys 0.027s 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":637,"lbm_read_time_us":9401,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26844,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":98560,"update_count":2000}
I20260812 06:20:31.666536  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:31.717602  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.051s	user 0.022s	sys 0.027s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20816,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.718137  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.742578  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.024s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.743048  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.753502  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.754048  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:31.790045  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.036s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1368,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1548,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:31.790752  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): free 112692317 bytes of WAL
I20260812 06:20:31.790974  3559 log_reader.cc:385] T 7edf3c82ed0a4c0dadbd851d26f1a6b1: removed 11 log segments from log reader
I20260812 06:20:31.791040  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000014 (ops 67-71)
I20260812 06:20:31.791095  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000015 (ops 72-76)
I20260812 06:20:31.791153  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000016 (ops 77-81)
I20260812 06:20:31.791196  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000017 (ops 82-86)
I20260812 06:20:31.791231  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000018 (ops 87-91)
I20260812 06:20:31.791265  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000019 (ops 92-96)
I20260812 06:20:31.791302  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000020 (ops 97-101)
I20260812 06:20:31.791339  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000021 (ops 102-106)
I20260812 06:20:31.791375  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000022 (ops 107-111)
I20260812 06:20:31.791414  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000023 (ops 112-116)
I20260812 06:20:31.791450  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000024 (ops 117-121)
I20260812 06:20:31.819176  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.028s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:20:31.819666  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): 462 bytes on disk
I20260812 06:20:31.820242  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.820895  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=3.181125
I20260812 06:20:31.838145  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.017s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4529,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:31.838656  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:31.849483  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.849993  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:32.075865  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.226s	user 0.164s	sys 0.052s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979859,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":544,"lbm_read_time_us":16533,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39231,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11776,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:20:32.076495  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=18.063937
I20260812 06:20:32.134040  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.057s	user 0.025s	sys 0.031s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26154,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:32.134920  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:32.146931  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.147532  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:32.308375  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.161s	user 0.148s	sys 0.012s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":13374,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32105,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":38016,"update_count":3000}
I20260812 06:20:32.309413  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=14.095187
I20260812 06:20:32.383292  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.074s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":43724,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:32.383816  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:32.405143  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4463,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.405637  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:32.417212  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4550,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.417958  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:32.599740  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.182s	user 0.159s	sys 0.019s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":602,"lbm_read_time_us":12462,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38086,"lbm_writes_lt_1ms":643,"mutex_wait_us":42,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:20:32.600453  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=14.095187
I20260812 06:20:32.652876  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.052s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20982,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.653520  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:32.664088  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.664795  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:32.833279  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.168s	user 0.120s	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":659,"lbm_read_time_us":11781,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34113,"lbm_writes_lt_1ms":543,"mutex_wait_us":346,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:20:32.833858  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:32.875204  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.041s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18329,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.875679  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:32.886909  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.011s	user 0.009s	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:32.887773  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:33.036337  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.148s	user 0.080s	sys 0.065s 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":1164,"lbm_read_time_us":12006,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23006,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:20:33.037376  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:33.086450  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.049s	user 0.028s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19333,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.087009  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:33.099915  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4960,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.100668  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:33.241382  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.140s	user 0.106s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":644,"lbm_read_time_us":12164,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22110,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:33.242058  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=10.126437
I20260812 06:20:33.293694  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.051s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18689,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.294219  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:33.307828  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.308540  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:33.340138  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushMRSOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.031s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1421,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1815,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:33.341389  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): free 133024613 bytes of WAL
I20260812 06:20:33.341691  3559 log_reader.cc:385] T 7edf3c82ed0a4c0dadbd851d26f1a6b1: removed 13 log segments from log reader
I20260812 06:20:33.341800  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000025 (ops 122-126)
I20260812 06:20:33.341869  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000026 (ops 127-130)
I20260812 06:20:33.341913  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000027 (ops 131-135)
I20260812 06:20:33.341954  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000028 (ops 136-140)
I20260812 06:20:33.341993  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000029 (ops 141-145)
I20260812 06:20:33.342031  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000030 (ops 146-150)
I20260812 06:20:33.342072  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000031 (ops 151-155)
I20260812 06:20:33.342105  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000032 (ops 156-160)
I20260812 06:20:33.342149  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000033 (ops 161-165)
I20260812 06:20:33.342199  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000034 (ops 166-170)
I20260812 06:20:33.342235  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000035 (ops 171-175)
I20260812 06:20:33.342271  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000036 (ops 176-180)
I20260812 06:20:33.342305  3559 log.cc:1079] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/7edf3c82ed0a4c0dadbd851d26f1a6b1/wal-000000037 (ops 181-185)
I20260812 06:20:33.377729  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: LogGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.036s	user 0.003s	sys 0.032s Metrics: {}
I20260812 06:20:33.378142  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): 483 bytes on disk
I20260812 06:20:33.378818  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: UndoDeltaBlockGCOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:20:33.379456  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=6.157687
I20260812 06:20:33.410825  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.031s	user 0.012s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11476,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:33.411356  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:33.581547  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.170s	user 0.140s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3930,"lbm_read_time_us":13403,"lbm_reads_lt_1ms":665,"lbm_write_time_us":33340,"lbm_writes_lt_1ms":643,"mutex_wait_us":1878,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17920,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:20:33.582332  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=14.095187
I20260812 06:20:33.627416  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.045s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19562,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.628024  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=2.188937
I20260812 06:20:33.643411  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: FlushDeltaMemStoresOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.015s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6019,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.643904  3656 maintenance_manager.cc:419] P 952f0338c6724715b31003c9bbc45f9c: Scheduling MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1): perf score=1.000000
I20260812 06:20:33.663789  3389 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.852s	user 1.787s	sys 0.130s
I20260812 06:20:33.759994  3389 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.096s	user 0.006s	sys 0.000s
I20260812 06:20:33.761022  3389 tablet_server.cc:179] TabletServer@127.3.79.65:0 shutting down...
I20260812 06:20:33.811189  3559 maintenance_manager.cc:643] P 952f0338c6724715b31003c9bbc45f9c: MajorDeltaCompactionOp(7edf3c82ed0a4c0dadbd851d26f1a6b1) complete. Timing: real 0.167s	user 0.131s	sys 0.036s 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":290,"lbm_read_time_us":11406,"lbm_reads_lt_1ms":568,"lbm_write_time_us":35318,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:20:33.811998  3389 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:33.815600  3389 tablet_replica.cc:333] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c: stopping tablet replica
I20260812 06:20:33.815917  3389 raft_consensus.cc:2243] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:33.816205  3389 raft_consensus.cc:2272] T 7edf3c82ed0a4c0dadbd851d26f1a6b1 P 952f0338c6724715b31003c9bbc45f9c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:34.090623  3389 tablet_server.cc:196] TabletServer@127.3.79.65:0 shutdown complete.
I20260812 06:20:34.096115  3389 master.cc:562] Master@127.3.79.126:36669 shutting down...
I20260812 06:20:34.101431  3389 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:34.101645  3389 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:34.101761  3389 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1d4f9616bc1c4ccab12f468634cd9e59: stopping tablet replica
I20260812 06:20:34.114374  3389 master.cc:584] Master@127.3.79.126:36669 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5648 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:34.213722  3389 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.79.126:44901
I20260812 06:20:34.214089  3389 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:34.216598  3708 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:34.216724  3389 server_base.cc:1061] running on GCE node
W20260812 06:20:34.216657  3712 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:34.216605  3709 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:34.217097  3389 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:34.217144  3389 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:34.217159  3389 hybrid_clock.cc:648] HybridClock initialized: now 1786515634217159 us; error 0 us; skew 500 ppm
I20260812 06:20:34.217948  3389 webserver.cc:533] Webserver started at http://127.3.79.126:37651/ using document root <none> and password file <none>
I20260812 06:20:34.218077  3389 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:34.218117  3389 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:34.218173  3389 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:34.218544  3389 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/master-0-root/instance:
uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-g170"
I20260812 06:20:34.220036  3389 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:34.221045  3719 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:34.221309  3389 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:34.221374  3389 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/master-0-root
uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-g170"
I20260812 06:20:34.221458  3389 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-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:34.237622  3389 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:34.238023  3389 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:34.242269  3389 rpc_server.cc:307] RPC server started. Bound to: 127.3.79.126:44901
I20260812 06:20:34.245774  3801 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.79.126:44901 every 8 connection(s)
I20260812 06:20:34.247186  3802 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:34.260923  3802 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6: Bootstrap starting.
I20260812 06:20:34.261900  3802 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:34.263049  3802 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6: No bootstrap required, opened a new log
I20260812 06:20:34.263484  3802 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6" member_type: VOTER }
I20260812 06:20:34.263608  3802 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:34.263675  3802 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3946f1c7bd5f4e9dbd165d9ddc205bc6, State: Initialized, Role: FOLLOWER
I20260812 06:20:34.263867  3802 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [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: "3946f1c7bd5f4e9dbd165d9ddc205bc6" member_type: VOTER }
I20260812 06:20:34.263975  3802 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:34.264021  3802 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:34.264076  3802 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:34.264849  3802 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6" member_type: VOTER }
I20260812 06:20:34.265002  3802 leader_election.cc:304] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [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: 3946f1c7bd5f4e9dbd165d9ddc205bc6; no voters: 
I20260812 06:20:34.265211  3802 leader_election.cc:290] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:34.265363  3805 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:34.265617  3805 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 1 LEADER]: Becoming Leader. State: Replica: 3946f1c7bd5f4e9dbd165d9ddc205bc6, State: Running, Role: LEADER
I20260812 06:20:34.265710  3802 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:34.265797  3805 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [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: "3946f1c7bd5f4e9dbd165d9ddc205bc6" member_type: VOTER }
I20260812 06:20:34.266324  3806 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6" member_type: VOTER } }
I20260812 06:20:34.266356  3808 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3946f1c7bd5f4e9dbd165d9ddc205bc6. Latest consensus state: current_term: 1 leader_uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3946f1c7bd5f4e9dbd165d9ddc205bc6" member_type: VOTER } }
I20260812 06:20:34.266433  3806 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:34.266451  3808 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:34.267022  3815 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:34.268158  3815 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:34.268404  3389 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:34.270884  3815 catalog_manager.cc:1383] Generated new cluster ID: 3692d7b9f76d413588b0891beb6b9c66
I20260812 06:20:34.270974  3815 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:34.297257  3815 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:34.297873  3815 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:34.305145  3815 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6: Generated new TSK 0
I20260812 06:20:34.305334  3815 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:34.333384  3389 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:34.335626  3834 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:34.335651  3844 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:34.335702  3837 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:34.335638  3389 server_base.cc:1061] running on GCE node
I20260812 06:20:34.336076  3389 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:34.336126  3389 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:34.336143  3389 hybrid_clock.cc:648] HybridClock initialized: now 1786515634336143 us; error 0 us; skew 500 ppm
I20260812 06:20:34.337110  3389 webserver.cc:533] Webserver started at http://127.3.79.65:40027/ using document root <none> and password file <none>
I20260812 06:20:34.337312  3389 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:34.337383  3389 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:34.337477  3389 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:34.337908  3389 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/instance:
uuid: "996835aece494690a9de23e54d328d2a"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-g170"
I20260812 06:20:34.339515  3389 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:34.340497  3854 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:34.340900  3389 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:34.340991  3389 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root
uuid: "996835aece494690a9de23e54d328d2a"
format_stamp: "Formatted at 2026-08-12 06:20:34 on dist-test-slave-g170"
I20260812 06:20:34.341091  3389 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-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:34.350097  3389 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:34.350457  3389 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:34.350759  3389 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:34.351226  3389 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:34.351293  3389 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:34.351366  3389 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:34.351414  3389 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:34.355903  3389 rpc_server.cc:307] RPC server started. Bound to: 127.3.79.65:42087
I20260812 06:20:34.355969  3960 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.79.65:42087 every 8 connection(s)
I20260812 06:20:34.366734  3961 heartbeater.cc:344] Connected to a master server at 127.3.79.126:44901
I20260812 06:20:34.366840  3961 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:34.367079  3961 heartbeater.cc:507] Master 127.3.79.126:44901 requested a full tablet report, sending...
I20260812 06:20:34.367753  3740 ts_manager.cc:194] Registered new tserver with Master: 996835aece494690a9de23e54d328d2a (127.3.79.65:42087)
I20260812 06:20:34.368459  3740 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33734
I20260812 06:20:34.368580  3389 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012184723s
I20260812 06:20:34.375681  3740 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33738:
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:34.384712  3900 tablet_service.cc:1511] Processing CreateTablet for tablet bd609bbc355c4ad48b7d6241d456bd58 (DEFAULT_TABLE table=heavy-update-compaction-test [id=122d6d5005ef4d699c0b8b6706f85f80]), partition=
I20260812 06:20:34.385058  3900 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bd609bbc355c4ad48b7d6241d456bd58. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:34.387154  3987 tablet_bootstrap.cc:492] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Bootstrap starting.
I20260812 06:20:34.388151  3987 tablet_bootstrap.cc:654] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:34.389315  3987 tablet_bootstrap.cc:492] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: No bootstrap required, opened a new log
I20260812 06:20:34.389436  3987 ts_tablet_manager.cc:1403] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:34.389963  3987 raft_consensus.cc:359] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996835aece494690a9de23e54d328d2a" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 42087 } }
I20260812 06:20:34.390079  3987 raft_consensus.cc:385] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:34.390115  3987 raft_consensus.cc:740] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 996835aece494690a9de23e54d328d2a, State: Initialized, Role: FOLLOWER
I20260812 06:20:34.390254  3987 consensus_queue.cc:260] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [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: "996835aece494690a9de23e54d328d2a" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 42087 } }
I20260812 06:20:34.390360  3987 raft_consensus.cc:399] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:34.390432  3987 raft_consensus.cc:493] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:34.390494  3987 raft_consensus.cc:3060] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:34.391199  3987 raft_consensus.cc:515] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996835aece494690a9de23e54d328d2a" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 42087 } }
I20260812 06:20:34.391319  3987 leader_election.cc:304] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [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: 996835aece494690a9de23e54d328d2a; no voters: 
I20260812 06:20:34.391469  3987 leader_election.cc:290] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:34.391604  3991 raft_consensus.cc:2804] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:34.391796  3961 heartbeater.cc:499] Master 127.3.79.126:44901 was elected leader, sending a full tablet report...
I20260812 06:20:34.391822  3987 ts_tablet_manager.cc:1434] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:34.391875  3991 raft_consensus.cc:697] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 1 LEADER]: Becoming Leader. State: Replica: 996835aece494690a9de23e54d328d2a, State: Running, Role: LEADER
I20260812 06:20:34.392012  3991 consensus_queue.cc:237] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [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: "996835aece494690a9de23e54d328d2a" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 42087 } }
I20260812 06:20:34.393369  3740 catalog_manager.cc:5719] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a reported cstate change: term changed from 0 to 1, leader changed from <none> to 996835aece494690a9de23e54d328d2a (127.3.79.65). New cstate: current_term: 1 leader_uuid: "996835aece494690a9de23e54d328d2a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "996835aece494690a9de23e54d328d2a" member_type: VOTER last_known_addr { host: "127.3.79.65" port: 42087 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:34.454012  3389 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.010s	sys 0.012s
I20260812 06:20:34.607205  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=19.054940
I20260812 06:20:34.768579  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.161s	user 0.121s	sys 0.035s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":820,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42839,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:34.769395  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling LogGCOp(bd609bbc355c4ad48b7d6241d456bd58): free 20743880 bytes of WAL
I20260812 06:20:34.769727  3865 log_reader.cc:385] T bd609bbc355c4ad48b7d6241d456bd58: removed 2 log segments from log reader
I20260812 06:20:34.769809  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000001 (ops 1-6)
I20260812 06:20:34.769868  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000002 (ops 7-11)
I20260812 06:20:34.774341  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: LogGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:34.774782  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:34.797328  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.022s	user 0.001s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7049,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.797899  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58): 16411392 bytes on disk
I20260812 06:20:34.798296  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:20:34.798741  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:34.942431  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.144s	user 0.089s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":629,"lbm_read_time_us":11450,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25190,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":364,"threads_started":5,"update_count":2000}
I20260812 06:20:34.943058  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=11.118625
I20260812 06:20:34.983659  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.040s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17759,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:34.984187  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:35.003309  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.019s	user 0.007s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5543,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:35.003896  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:35.169091  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.165s	user 0.113s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":165,"lbm_read_time_us":12075,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26006,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2000}
I20260812 06:20:35.169636  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:35.232381  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.063s	user 0.033s	sys 0.022s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22230,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.232973  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:35.244650  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4578,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.245160  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:35.433439  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.188s	user 0.123s	sys 0.052s 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":1195,"lbm_read_time_us":12927,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29375,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:20:35.434144  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:35.500511  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.066s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25986,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.501231  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:35.518692  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.017s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.519295  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:35.710726  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.191s	user 0.119s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1073,"lbm_read_time_us":13650,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31143,"lbm_writes_lt_1ms":543,"mutex_wait_us":346,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:35.711263  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=18.063937
I20260812 06:20:35.788630  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.077s	user 0.042s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":30136,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:35.789471  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:35.807693  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7021,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.808203  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:36.009358  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.201s	user 0.138s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":5993,"dirs.run_cpu_time_us":789,"dirs.run_wall_time_us":2614,"lbm_read_time_us":14251,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33721,"lbm_writes_lt_1ms":643,"mutex_wait_us":2885,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:20:36.010298  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:36.074064  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.064s	user 0.039s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23648,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.074589  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:36.090971  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.016s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.091552  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:36.129665  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.038s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1302,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2442,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:36.130290  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling LogGCOp(bd609bbc355c4ad48b7d6241d456bd58): free 120553325 bytes of WAL
I20260812 06:20:36.130532  3865 log_reader.cc:385] T bd609bbc355c4ad48b7d6241d456bd58: removed 12 log segments from log reader
I20260812 06:20:36.130594  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000003 (ops 12-16)
I20260812 06:20:36.130695  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000004 (ops 17-20)
I20260812 06:20:36.130752  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000005 (ops 21-25)
I20260812 06:20:36.130798  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000006 (ops 26-30)
I20260812 06:20:36.130842  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000007 (ops 31-35)
I20260812 06:20:36.130883  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000008 (ops 36-40)
I20260812 06:20:36.130928  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000009 (ops 41-45)
I20260812 06:20:36.130971  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000010 (ops 46-50)
I20260812 06:20:36.131042  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000011 (ops 51-55)
I20260812 06:20:36.131102  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000012 (ops 56-60)
I20260812 06:20:36.131156  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000013 (ops 61-64)
I20260812 06:20:36.131201  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000014 (ops 65-69)
I20260812 06:20:36.160889  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: LogGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:36.161266  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58): 472 bytes on disk
I20260812 06:20:36.161671  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:36.162096  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=6.157687
I20260812 06:20:36.186813  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.025s	user 0.006s	sys 0.014s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":9423,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:36.187263  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:36.431747  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.244s	user 0.172s	sys 0.072s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":182,"lbm_read_time_us":17113,"lbm_reads_lt_1ms":769,"lbm_write_time_us":44949,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":147,"threads_started":2,"update_count":3500}
I20260812 06:20:36.432477  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=18.063937
I20260812 06:20:36.497539  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.065s	user 0.037s	sys 0.027s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29354,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:36.498565  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:36.516131  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6570,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.516868  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:36.693832  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.177s	user 0.121s	sys 0.054s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":13871,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37434,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":3000}
I20260812 06:20:36.694514  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:36.739909  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.045s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20095,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.740633  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:36.757762  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.758368  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:36.934208  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.176s	user 0.119s	sys 0.051s 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":1092,"lbm_read_time_us":11015,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31843,"lbm_writes_lt_1ms":543,"mutex_wait_us":452,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:20:36.934854  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:36.996567  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.061s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26419,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.997418  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:37.169612  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.172s	user 0.120s	sys 0.050s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":416,"lbm_read_time_us":11303,"lbm_reads_lt_1ms":467,"lbm_write_time_us":31236,"lbm_writes_lt_1ms":443,"mutex_wait_us":160,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.170639  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=11.118625
I20260812 06:20:37.205588  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.035s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14244,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:37.206117  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:37.235435  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.029s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6061,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:37.236033  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:37.249651  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.013s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5359,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.250242  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:37.439302  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.189s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":116,"lbm_read_time_us":12864,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30443,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2500}
I20260812 06:20:37.440026  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:37.489773  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.050s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":20299,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.490314  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:37.502590  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4236,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.503249  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:37.670550  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.167s	user 0.127s	sys 0.034s 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":921,"lbm_read_time_us":12655,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30241,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:20:37.671146  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:37.720384  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.049s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19039,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.721024  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:37.732379  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.733250  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:37.765383  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":288,"dirs.run_wall_time_us":1516,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1651,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:37.766078  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling LogGCOp(bd609bbc355c4ad48b7d6241d456bd58): free 133024385 bytes of WAL
I20260812 06:20:37.766345  3865 log_reader.cc:385] T bd609bbc355c4ad48b7d6241d456bd58: removed 13 log segments from log reader
I20260812 06:20:37.766394  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000015 (ops 70-74)
I20260812 06:20:37.766446  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000016 (ops 75-79)
I20260812 06:20:37.766491  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000017 (ops 80-84)
I20260812 06:20:37.766553  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000018 (ops 85-89)
I20260812 06:20:37.766597  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000019 (ops 90-94)
I20260812 06:20:37.766645  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000020 (ops 95-98)
I20260812 06:20:37.766724  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000021 (ops 99-103)
I20260812 06:20:37.766769  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000022 (ops 104-108)
I20260812 06:20:37.766810  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000023 (ops 109-113)
I20260812 06:20:37.766850  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000024 (ops 114-118)
I20260812 06:20:37.766891  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000025 (ops 119-123)
I20260812 06:20:37.766928  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000026 (ops 124-128)
I20260812 06:20:37.766971  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000027 (ops 129-133)
I20260812 06:20:37.797665  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: LogGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:37.798439  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58): 482 bytes on disk
I20260812 06:20:37.798943  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:37.799458  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=6.157687
I20260812 06:20:37.830663  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.031s	user 0.015s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10423,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:37.831240  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:38.084493  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.253s	user 0.142s	sys 0.108s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979631,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":7407,"lbm_read_time_us":15192,"lbm_reads_lt_1ms":765,"lbm_write_time_us":42838,"lbm_writes_lt_1ms":743,"mutex_wait_us":2536,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:20:38.085249  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=18.063937
I20260812 06:20:38.157289  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.072s	user 0.034s	sys 0.027s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":27752,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:38.157799  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:38.168583  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.169065  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:38.372818  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.204s	user 0.123s	sys 0.078s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2981,"lbm_read_time_us":13646,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32520,"lbm_writes_lt_1ms":643,"mutex_wait_us":2111,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":3000}
I20260812 06:20:38.373559  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:38.429373  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.056s	user 0.038s	sys 0.017s Metrics: {"bytes_written":16409910,"delete_count":0,"lbm_write_time_us":25273,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:38.429921  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:38.455682  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.026s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.456252  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:38.466600  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.467460  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:38.684041  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.216s	user 0.140s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877228,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1061,"lbm_read_time_us":14796,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33121,"lbm_writes_lt_1ms":643,"mutex_wait_us":363,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":3000}
I20260812 06:20:38.684646  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=18.063937
I20260812 06:20:38.745465  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.061s	user 0.043s	sys 0.014s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25881,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:38.745970  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:38.762351  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6390,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.762986  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:38.957968  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.195s	user 0.139s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":90,"lbm_read_time_us":12536,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34402,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":3000}
I20260812 06:20:38.958755  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:39.010097  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.051s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.010610  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:39.023285  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4821,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.023834  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:39.192785  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.169s	user 0.113s	sys 0.044s 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":197,"lbm_read_time_us":12227,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28858,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:20:39.193437  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:39.238693  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.045s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19388,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.239161  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:39.263989  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushMRSOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.025s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":318,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1314,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1435,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:39.264606  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling LogGCOp(bd609bbc355c4ad48b7d6241d456bd58): free 120553688 bytes of WAL
I20260812 06:20:39.264873  3865 log_reader.cc:385] T bd609bbc355c4ad48b7d6241d456bd58: removed 12 log segments from log reader
I20260812 06:20:39.264933  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000028 (ops 134-138)
I20260812 06:20:39.264986  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000029 (ops 139-142)
I20260812 06:20:39.265045  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000030 (ops 143-147)
I20260812 06:20:39.265086  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000031 (ops 148-152)
I20260812 06:20:39.265127  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000032 (ops 153-157)
I20260812 06:20:39.265167  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000033 (ops 158-162)
I20260812 06:20:39.265205  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000034 (ops 163-167)
I20260812 06:20:39.265242  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000035 (ops 168-172)
I20260812 06:20:39.265281  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000036 (ops 173-176)
I20260812 06:20:39.265318  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000037 (ops 177-181)
I20260812 06:20:39.265355  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000038 (ops 182-186)
I20260812 06:20:39.265393  3865 log.cc:1079] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: Deleting log segment in path: /tmp/dist-test-taskbov0LD/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515628554171-3389-0/minicluster-data/ts-0-root/wals/bd609bbc355c4ad48b7d6241d456bd58/wal-000000039 (ops 187-191)
I20260812 06:20:39.293699  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: LogGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:20:39.294082  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58): 472 bytes on disk
I20260812 06:20:39.294663  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: UndoDeltaBlockGCOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:20:39.295203  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=3.181125
I20260812 06:20:39.313136  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4864,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:39.313551  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=2.188937
I20260812 06:20:39.323081  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3646,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:39.323446  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:39.508931  3389 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.055s	user 1.831s	sys 0.179s
I20260812 06:20:39.534063  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.210s	user 0.153s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":14065,"lbm_reads_lt_1ms":669,"lbm_write_time_us":35276,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":3000}
I20260812 06:20:39.534574  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=14.095187
I20260812 06:20:39.567675  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: FlushDeltaMemStoresOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.033s	user 0.018s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16208,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:39.568301  3962 maintenance_manager.cc:419] P 996835aece494690a9de23e54d328d2a: Scheduling MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58): perf score=1.000000
I20260812 06:20:39.609107  3389 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.100s	user 0.003s	sys 0.000s
I20260812 06:20:39.609694  3389 tablet_server.cc:179] TabletServer@127.3.79.65:0 shutting down...
I20260812 06:20:39.700589  3865 maintenance_manager.cc:643] P 996835aece494690a9de23e54d328d2a: MajorDeltaCompactionOp(bd609bbc355c4ad48b7d6241d456bd58) complete. Timing: real 0.132s	user 0.105s	sys 0.023s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":546,"lbm_read_time_us":13142,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24386,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.701310  3389 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:39.701609  3389 tablet_replica.cc:333] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a: stopping tablet replica
I20260812 06:20:39.701773  3389 raft_consensus.cc:2243] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:39.701953  3389 raft_consensus.cc:2272] T bd609bbc355c4ad48b7d6241d456bd58 P 996835aece494690a9de23e54d328d2a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:39.715879  3389 tablet_server.cc:196] TabletServer@127.3.79.65:0 shutdown complete.
I20260812 06:20:39.739061  3389 master.cc:562] Master@127.3.79.126:44901 shutting down...
I20260812 06:20:39.742538  3389 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:39.742740  3389 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:39.742828  3389 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3946f1c7bd5f4e9dbd165d9ddc205bc6: stopping tablet replica
I20260812 06:20:39.755208  3389 master.cc:584] Master@127.3.79.126:44901 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5635 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11285 ms total)

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