[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:47.505148  2336 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.72.62:46115
I20260812 06:17:47.506268  2336 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:47.506915  2336 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:47.513845  2344 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:47.513919  2336 server_base.cc:1061] running on GCE node
W20260812 06:17:47.513855  2342 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:47.514204  2341 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:47.514796  2336 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:47.514927  2336 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:47.514981  2336 hybrid_clock.cc:648] HybridClock initialized: now 1786515467514978 us; error 0 us; skew 500 ppm
I20260812 06:17:47.517139  2336 webserver.cc:533] Webserver started at http://127.2.72.62:32781/ using document root <none> and password file <none>
I20260812 06:17:47.517755  2336 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:47.517848  2336 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:47.518124  2336 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:47.519814  2336 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/master-0-root/instance:
uuid: "4df49b64e2a74e7a8aeac4a5a295475a"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-1jjb"
I20260812 06:17:47.523392  2336 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:17:47.525601  2349 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.526722  2336 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:17:47.526868  2336 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/master-0-root
uuid: "4df49b64e2a74e7a8aeac4a5a295475a"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-1jjb"
I20260812 06:17:47.526986  2336 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:47.571982  2336 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:47.572743  2336 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:47.572939  2336 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:47.581014  2336 rpc_server.cc:307] RPC server started. Bound to: 127.2.72.62:46115
I20260812 06:17:47.581041  2409 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.72.62:46115 every 8 connection(s)
I20260812 06:17:47.583357  2410 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:47.588951  2410 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a: Bootstrap starting.
I20260812 06:17:47.591391  2410 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:47.592455  2410 log.cc:826] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:47.594267  2410 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a: No bootstrap required, opened a new log
I20260812 06:17:47.597194  2410 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4df49b64e2a74e7a8aeac4a5a295475a" member_type: VOTER }
I20260812 06:17:47.597359  2410 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:47.597455  2410 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4df49b64e2a74e7a8aeac4a5a295475a, State: Initialized, Role: FOLLOWER
I20260812 06:17:47.598088  2410 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [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: "4df49b64e2a74e7a8aeac4a5a295475a" member_type: VOTER }
I20260812 06:17:47.598254  2410 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:47.598331  2410 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:47.598495  2410 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:47.599304  2410 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4df49b64e2a74e7a8aeac4a5a295475a" member_type: VOTER }
I20260812 06:17:47.599766  2410 leader_election.cc:304] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [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: 4df49b64e2a74e7a8aeac4a5a295475a; no voters: 
I20260812 06:17:47.600188  2410 leader_election.cc:290] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:47.600306  2413 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:47.600582  2413 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 1 LEADER]: Becoming Leader. State: Replica: 4df49b64e2a74e7a8aeac4a5a295475a, State: Running, Role: LEADER
I20260812 06:17:47.601055  2413 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [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: "4df49b64e2a74e7a8aeac4a5a295475a" member_type: VOTER }
I20260812 06:17:47.601374  2410 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:47.603288  2417 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4df49b64e2a74e7a8aeac4a5a295475a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4df49b64e2a74e7a8aeac4a5a295475a" member_type: VOTER } }
I20260812 06:17:47.603417  2417 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:47.603621  2415 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4df49b64e2a74e7a8aeac4a5a295475a. Latest consensus state: current_term: 1 leader_uuid: "4df49b64e2a74e7a8aeac4a5a295475a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4df49b64e2a74e7a8aeac4a5a295475a" member_type: VOTER } }
I20260812 06:17:47.603705  2415 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:47.603790  2424 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:47.606606  2424 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:47.606909  2336 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:47.611649  2424 catalog_manager.cc:1383] Generated new cluster ID: 3241705745a6414e9dcc740b71ed8926
I20260812 06:17:47.611734  2424 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:47.617784  2424 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:47.618919  2424 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:47.641953  2424 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a: Generated new TSK 0
I20260812 06:17:47.642803  2424 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:47.671845  2336 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:47.674702  2438 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:47.674805  2436 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:47.674790  2336 server_base.cc:1061] running on GCE node
W20260812 06:17:47.674732  2435 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:47.675236  2336 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:47.675294  2336 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:47.675318  2336 hybrid_clock.cc:648] HybridClock initialized: now 1786515467675318 us; error 0 us; skew 500 ppm
I20260812 06:17:47.676295  2336 webserver.cc:533] Webserver started at http://127.2.72.1:45451/ using document root <none> and password file <none>
I20260812 06:17:47.676465  2336 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:47.676524  2336 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:47.676594  2336 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:47.677045  2336 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/instance:
uuid: "cacacb9564994aad86bf7cdb88224c13"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-1jjb"
I20260812 06:17:47.678874  2336 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:47.679983  2443 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.680272  2336 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:47.680352  2336 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root
uuid: "cacacb9564994aad86bf7cdb88224c13"
format_stamp: "Formatted at 2026-08-12 06:17:47 on dist-test-slave-1jjb"
I20260812 06:17:47.680424  2336 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:47.703233  2336 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:47.703779  2336 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:47.704471  2336 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:47.705535  2336 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:47.705605  2336 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.705663  2336 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:47.705686  2336 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:47.713083  2336 rpc_server.cc:307] RPC server started. Bound to: 127.2.72.1:43809
I20260812 06:17:47.713308  2507 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.72.1:43809 every 8 connection(s)
I20260812 06:17:47.723156  2508 heartbeater.cc:344] Connected to a master server at 127.2.72.62:46115
I20260812 06:17:47.723431  2508 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:47.723918  2508 heartbeater.cc:507] Master 127.2.72.62:46115 requested a full tablet report, sending...
I20260812 06:17:47.725373  2368 ts_manager.cc:194] Registered new tserver with Master: cacacb9564994aad86bf7cdb88224c13 (127.2.72.1:43809)
I20260812 06:17:47.726171  2336 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012419256s
I20260812 06:17:47.726545  2368 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38378
I20260812 06:17:47.736039  2368 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38386:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:47.750378  2471 tablet_service.cc:1511] Processing CreateTablet for tablet 49dbaaf785394e46bcdf5d9e13988ace (DEFAULT_TABLE table=heavy-update-compaction-test [id=be5888267c2547df95199d97cee604b2]), partition=
I20260812 06:17:47.750865  2471 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 49dbaaf785394e46bcdf5d9e13988ace. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:47.753983  2524 tablet_bootstrap.cc:492] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Bootstrap starting.
I20260812 06:17:47.755092  2524 tablet_bootstrap.cc:654] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:47.756349  2524 tablet_bootstrap.cc:492] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: No bootstrap required, opened a new log
I20260812 06:17:47.756482  2524 ts_tablet_manager.cc:1403] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:47.756928  2524 raft_consensus.cc:359] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cacacb9564994aad86bf7cdb88224c13" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 43809 } }
I20260812 06:17:47.757069  2524 raft_consensus.cc:385] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:47.757121  2524 raft_consensus.cc:740] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cacacb9564994aad86bf7cdb88224c13, State: Initialized, Role: FOLLOWER
I20260812 06:17:47.757277  2524 consensus_queue.cc:260] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [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: "cacacb9564994aad86bf7cdb88224c13" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 43809 } }
I20260812 06:17:47.757375  2524 raft_consensus.cc:399] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:47.757424  2524 raft_consensus.cc:493] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:47.757476  2524 raft_consensus.cc:3060] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:47.758462  2524 raft_consensus.cc:515] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cacacb9564994aad86bf7cdb88224c13" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 43809 } }
I20260812 06:17:47.758622  2524 leader_election.cc:304] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [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: cacacb9564994aad86bf7cdb88224c13; no voters: 
I20260812 06:17:47.758886  2524 leader_election.cc:290] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:47.758989  2526 raft_consensus.cc:2804] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:47.759171  2526 raft_consensus.cc:697] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 1 LEADER]: Becoming Leader. State: Replica: cacacb9564994aad86bf7cdb88224c13, State: Running, Role: LEADER
I20260812 06:17:47.759280  2524 ts_tablet_manager.cc:1434] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:47.759379  2526 consensus_queue.cc:237] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [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: "cacacb9564994aad86bf7cdb88224c13" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 43809 } }
I20260812 06:17:47.759613  2508 heartbeater.cc:499] Master 127.2.72.62:46115 was elected leader, sending a full tablet report...
I20260812 06:17:47.762650  2368 catalog_manager.cc:5719] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 reported cstate change: term changed from 0 to 1, leader changed from <none> to cacacb9564994aad86bf7cdb88224c13 (127.2.72.1). New cstate: current_term: 1 leader_uuid: "cacacb9564994aad86bf7cdb88224c13" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cacacb9564994aad86bf7cdb88224c13" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 43809 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:47.837826  2336 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.024s	sys 0.012s
I20260812 06:17:47.964263  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=15.086190
I20260812 06:17:48.124043  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.159s	user 0.121s	sys 0.031s Metrics: {"bytes_written":11897250,"cfile_init":1,"compiler_manager_pool.queue_time_us":218,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":868,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37745,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":139,"threads_started":1,"update_count":1450}
I20260812 06:17:48.125404  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling LogGCOp(49dbaaf785394e46bcdf5d9e13988ace): free 20743880 bytes of WAL
I20260812 06:17:48.125728  2448 log_reader.cc:385] T 49dbaaf785394e46bcdf5d9e13988ace: removed 2 log segments from log reader
I20260812 06:17:48.125794  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000001 (ops 1-6)
I20260812 06:17:48.125852  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000002 (ops 7-11)
I20260812 06:17:48.131872  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: LogGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:48.132306  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling UndoDeltaBlockGCOp(49dbaaf785394e46bcdf5d9e13988ace): 12719213 bytes on disk
I20260812 06:17:48.132984  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: UndoDeltaBlockGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.133420  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:48.154863  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.021s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.155330  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:48.291039  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.135s	user 0.123s	sys 0.012s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1202,"lbm_read_time_us":7808,"lbm_reads_lt_1ms":450,"lbm_write_time_us":25651,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":446,"threads_started":5,"update_count":1950}
I20260812 06:17:48.291868  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:48.328620  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.037s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16025,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.329178  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:48.340091  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.340761  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:48.460533  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.120s	user 0.092s	sys 0.028s 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":246,"lbm_read_time_us":9321,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23360,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:17:48.461090  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:48.510633  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.049s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18341,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.511165  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:48.522992  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.523584  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:48.647471  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.124s	user 0.096s	sys 0.028s 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":208,"lbm_read_time_us":10176,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22738,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:17:48.648209  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:48.705080  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.057s	user 0.021s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15069,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.705755  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:48.724287  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.018s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.724860  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:48.873116  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.148s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1051,"lbm_read_time_us":12319,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23339,"lbm_writes_lt_1ms":443,"mutex_wait_us":347,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2000}
I20260812 06:17:48.873720  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:48.917829  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.044s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17698,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:48.918282  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:48.928841  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.929502  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:49.059404  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.130s	user 0.103s	sys 0.026s 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":1926,"lbm_read_time_us":10331,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24469,"lbm_writes_lt_1ms":443,"mutex_wait_us":571,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:17:49.060191  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:49.101472  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.041s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18230,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.101969  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:49.121675  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.122279  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:49.255175  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.133s	user 0.112s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":8203,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28833,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:17:49.256172  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:49.301889  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.045s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17425,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.302472  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:49.318383  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.318998  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:49.450189  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.131s	user 0.119s	sys 0.012s 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":641,"lbm_read_time_us":10385,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23706,"lbm_writes_lt_1ms":443,"mutex_wait_us":352,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":29568,"update_count":2000}
I20260812 06:17:49.450956  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:49.507741  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.057s	user 0.018s	sys 0.035s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20979,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.508395  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:49.519083  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.519600  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:49.564376  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.045s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1491,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:49.565412  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling LogGCOp(49dbaaf785394e46bcdf5d9e13988ace): free 124257246 bytes of WAL
I20260812 06:17:49.565689  2448 log_reader.cc:385] T 49dbaaf785394e46bcdf5d9e13988ace: removed 12 log segments from log reader
I20260812 06:17:49.565733  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000003 (ops 12-16)
I20260812 06:17:49.565763  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000004 (ops 17-20)
I20260812 06:17:49.565825  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000005 (ops 21-25)
I20260812 06:17:49.565858  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000006 (ops 26-30)
I20260812 06:17:49.565913  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000007 (ops 31-35)
I20260812 06:17:49.565974  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000008 (ops 36-40)
I20260812 06:17:49.566018  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000009 (ops 41-45)
I20260812 06:17:49.566061  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000010 (ops 46-50)
I20260812 06:17:49.566099  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000011 (ops 51-55)
I20260812 06:17:49.566138  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000012 (ops 56-60)
I20260812 06:17:49.566175  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000013 (ops 61-65)
I20260812 06:17:49.566213  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000014 (ops 66-70)
I20260812 06:17:49.595053  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: LogGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:49.595585  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling UndoDeltaBlockGCOp(49dbaaf785394e46bcdf5d9e13988ace): 483 bytes on disk
I20260812 06:17:49.596635  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: UndoDeltaBlockGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.001s	user 0.001s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":160,"lbm_reads_lt_1ms":4}
I20260812 06:17:49.597288  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:49.613699  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.016s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4149,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.614135  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:49.624577  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.625120  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:49.836676  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.211s	user 0.142s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":168,"lbm_read_time_us":15740,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35695,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:17:49.837342  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=14.095187
I20260812 06:17:49.885974  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.047s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.886579  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:50.046038  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.159s	user 0.101s	sys 0.055s 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":784,"lbm_read_time_us":10922,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26306,"lbm_writes_lt_1ms":443,"mutex_wait_us":205,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:17:50.046707  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=11.118625
I20260812 06:17:50.085083  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16741,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:50.085755  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:50.104683  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.019s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6256,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.105176  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:50.235057  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.130s	user 0.101s	sys 0.028s 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":1082,"lbm_read_time_us":8683,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24527,"lbm_writes_lt_1ms":443,"mutex_wait_us":436,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:50.235735  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:50.280249  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.044s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307578,"delete_count":0,"lbm_write_time_us":22547,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.281117  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:50.308869  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.028s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6477,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.309425  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:50.320134  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.320640  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:50.478546  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.157s	user 0.132s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774896,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":304,"lbm_read_time_us":11105,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31866,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:50.479385  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:50.516714  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.037s	user 0.033s	sys 0.003s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16058,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.517269  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:50.534013  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6436,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.534554  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:50.662979  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.128s	user 0.112s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":421,"lbm_read_time_us":8558,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26485,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.664027  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:50.717633  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.053s	user 0.028s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18426,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.718261  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:50.735074  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.735670  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:50.892673  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.157s	user 0.117s	sys 0.040s 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":374,"lbm_read_time_us":12180,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26449,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:17:50.893422  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:50.941326  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.048s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.941855  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:50.953190  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.953789  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:51.080124  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.126s	user 0.102s	sys 0.024s 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":565,"lbm_read_time_us":9856,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23795,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:17:51.080821  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=10.126437
I20260812 06:17:51.119941  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.039s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16251,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:51.120548  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:51.132450  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.133005  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:51.164682  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.031s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1425,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1772,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:51.165791  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling LogGCOp(49dbaaf785394e46bcdf5d9e13988ace): free 129320520 bytes of WAL
I20260812 06:17:51.166069  2448 log_reader.cc:385] T 49dbaaf785394e46bcdf5d9e13988ace: removed 13 log segments from log reader
I20260812 06:17:51.166116  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000015 (ops 71-75)
I20260812 06:17:51.166146  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000016 (ops 76-80)
I20260812 06:17:51.166209  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000017 (ops 81-85)
I20260812 06:17:51.166251  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000018 (ops 86-90)
I20260812 06:17:51.166299  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000019 (ops 91-95)
I20260812 06:17:51.166361  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000020 (ops 96-100)
I20260812 06:17:51.166409  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000021 (ops 101-104)
I20260812 06:17:51.166455  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000022 (ops 105-109)
I20260812 06:17:51.166498  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000023 (ops 110-114)
I20260812 06:17:51.166538  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000024 (ops 115-118)
I20260812 06:17:51.166579  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000025 (ops 119-123)
I20260812 06:17:51.166618  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000026 (ops 124-128)
I20260812 06:17:51.166659  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000027 (ops 129-133)
I20260812 06:17:51.199311  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: LogGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:51.199764  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=3.181125
I20260812 06:17:51.217655  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4635981,"delete_count":0,"lbm_write_time_us":7263,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:17:51.218111  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling UndoDeltaBlockGCOp(49dbaaf785394e46bcdf5d9e13988ace): 482 bytes on disk
I20260812 06:17:51.218508  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: UndoDeltaBlockGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.218998  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:51.229859  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3904,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:17:51.230324  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:51.405695  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.175s	user 0.137s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1056,"lbm_read_time_us":13447,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36185,"lbm_writes_lt_1ms":643,"mutex_wait_us":523,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:17:51.406410  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=14.095187
I20260812 06:17:51.459347  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.053s	user 0.020s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19780,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.459990  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:51.476187  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.016s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6084,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.476850  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:51.641953  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.165s	user 0.129s	sys 0.029s 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":1015,"lbm_read_time_us":11346,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31914,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:17:51.642616  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=14.095187
I20260812 06:17:51.700482  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.058s	user 0.040s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":29202,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.701149  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:51.719161  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.018s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6860,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.719717  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:51.872016  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.152s	user 0.128s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1778,"lbm_read_time_us":12122,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28932,"lbm_writes_lt_1ms":543,"mutex_wait_us":890,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:51.872849  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=11.118625
I20260812 06:17:51.937132  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.064s	user 0.033s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":22988,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.937606  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=6.157687
I20260812 06:17:51.962937  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.025s	user 0.017s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9747,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:51.963614  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:52.124225  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.160s	user 0.131s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":9308,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31101,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:52.125044  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=14.095187
I20260812 06:17:52.179355  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.054s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19533,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.179909  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:52.190433  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.191082  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:52.367988  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.177s	user 0.135s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1444,"lbm_read_time_us":11993,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28747,"lbm_writes_lt_1ms":543,"mutex_wait_us":351,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:17:52.368618  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=14.095187
I20260812 06:17:52.422868  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.054s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409950,"delete_count":0,"lbm_write_time_us":23270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.423440  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:52.571017  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.147s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672206,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":258,"lbm_read_time_us":10317,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23877,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:17:52.571760  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=14.095187
I20260812 06:17:52.619760  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.048s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20723,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.620329  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:52.636276  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.636842  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:52.677492  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushMRSOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.040s	user 0.031s	sys 0.002s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":157,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1677,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:52.678300  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling LogGCOp(49dbaaf785394e46bcdf5d9e13988ace): free 133024602 bytes of WAL
I20260812 06:17:52.678622  2448 log_reader.cc:385] T 49dbaaf785394e46bcdf5d9e13988ace: removed 13 log segments from log reader
I20260812 06:17:52.678683  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000028 (ops 134-138)
I20260812 06:17:52.678726  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000029 (ops 139-143)
I20260812 06:17:52.678759  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000030 (ops 144-148)
I20260812 06:17:52.678794  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000031 (ops 149-153)
I20260812 06:17:52.678822  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000032 (ops 154-158)
I20260812 06:17:52.678853  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000033 (ops 159-162)
I20260812 06:17:52.678879  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000034 (ops 163-167)
I20260812 06:17:52.678901  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000035 (ops 168-172)
I20260812 06:17:52.678930  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000036 (ops 173-177)
I20260812 06:17:52.678957  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000037 (ops 178-182)
I20260812 06:17:52.678992  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000038 (ops 183-187)
I20260812 06:17:52.679021  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000039 (ops 188-192)
I20260812 06:17:52.679044  2448 log.cc:1079] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/49dbaaf785394e46bcdf5d9e13988ace/wal-000000040 (ops 193-197)
I20260812 06:17:52.712908  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: LogGCOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.034s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:17:52.713414  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:52.732486  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.019s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.732919  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=2.188937
I20260812 06:17:52.743528  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: FlushDeltaMemStoresOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.743975  2510 maintenance_manager.cc:419] P cacacb9564994aad86bf7cdb88224c13: Scheduling MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace): perf score=1.000000
I20260812 06:17:52.788443  2336 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.951s	user 1.865s	sys 0.135s
I20260812 06:17:52.891316  2336 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.102s	user 0.001s	sys 0.000s
I20260812 06:17:52.891973  2336 tablet_server.cc:179] TabletServer@127.2.72.1:0 shutting down...
I20260812 06:17:52.956452  2448 maintenance_manager.cc:643] P cacacb9564994aad86bf7cdb88224c13: MajorDeltaCompactionOp(49dbaaf785394e46bcdf5d9e13988ace) complete. Timing: real 0.212s	user 0.159s	sys 0.053s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":867,"lbm_read_time_us":16957,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37233,"lbm_writes_lt_1ms":743,"mutex_wait_us":133,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:17:52.957937  2336 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:52.958456  2336 tablet_replica.cc:333] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13: stopping tablet replica
I20260812 06:17:52.958736  2336 raft_consensus.cc:2243] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:52.959020  2336 raft_consensus.cc:2272] T 49dbaaf785394e46bcdf5d9e13988ace P cacacb9564994aad86bf7cdb88224c13 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:52.975319  2336 tablet_server.cc:196] TabletServer@127.2.72.1:0 shutdown complete.
I20260812 06:17:53.015065  2336 master.cc:562] Master@127.2.72.62:46115 shutting down...
I20260812 06:17:53.018718  2336 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:53.018927  2336 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:53.019023  2336 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4df49b64e2a74e7a8aeac4a5a295475a: stopping tablet replica
I20260812 06:17:53.031481  2336 master.cc:584] Master@127.2.72.62:46115 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5618 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:53.134918  2336 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.72.62:40085
I20260812 06:17:53.135293  2336 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.137669  2549 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.137799  2547 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.137810  2336 server_base.cc:1061] running on GCE node
W20260812 06:17:53.138144  2546 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.138375  2336 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.138439  2336 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:53.138463  2336 hybrid_clock.cc:648] HybridClock initialized: now 1786515473138462 us; error 0 us; skew 500 ppm
I20260812 06:17:53.139358  2336 webserver.cc:533] Webserver started at http://127.2.72.62:36959/ using document root <none> and password file <none>
I20260812 06:17:53.139552  2336 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.139623  2336 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.139705  2336 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.140198  2336 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/master-0-root/instance:
uuid: "64a95902fd2040c894c51de7689308ed"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-1jjb"
I20260812 06:17:53.141762  2336 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:53.142737  2555 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.142997  2336 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:53.143090  2336 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/master-0-root
uuid: "64a95902fd2040c894c51de7689308ed"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-1jjb"
I20260812 06:17:53.143178  2336 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:53.165685  2336 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.166139  2336 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.170640  2336 rpc_server.cc:307] RPC server started. Bound to: 127.2.72.62:40085
I20260812 06:17:53.173306  2610 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.174479  2609 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.72.62:40085 every 8 connection(s)
I20260812 06:17:53.178485  2610 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed: Bootstrap starting.
I20260812 06:17:53.179301  2610 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.180379  2610 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed: No bootstrap required, opened a new log
I20260812 06:17:53.180796  2610 raft_consensus.cc:359] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64a95902fd2040c894c51de7689308ed" member_type: VOTER }
I20260812 06:17:53.180881  2610 raft_consensus.cc:385] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.180904  2610 raft_consensus.cc:740] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 64a95902fd2040c894c51de7689308ed, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.181097  2610 consensus_queue.cc:260] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [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: "64a95902fd2040c894c51de7689308ed" member_type: VOTER }
I20260812 06:17:53.181169  2610 raft_consensus.cc:399] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.181231  2610 raft_consensus.cc:493] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.181304  2610 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.181977  2610 raft_consensus.cc:515] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64a95902fd2040c894c51de7689308ed" member_type: VOTER }
I20260812 06:17:53.182116  2610 leader_election.cc:304] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [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: 64a95902fd2040c894c51de7689308ed; no voters: 
I20260812 06:17:53.182343  2610 leader_election.cc:290] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.182564  2613 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.182785  2610 sys_catalog.cc:565] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:53.182797  2613 raft_consensus.cc:697] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 1 LEADER]: Becoming Leader. State: Replica: 64a95902fd2040c894c51de7689308ed, State: Running, Role: LEADER
I20260812 06:17:53.182948  2613 consensus_queue.cc:237] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [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: "64a95902fd2040c894c51de7689308ed" member_type: VOTER }
I20260812 06:17:53.183434  2614 sys_catalog.cc:455] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "64a95902fd2040c894c51de7689308ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64a95902fd2040c894c51de7689308ed" member_type: VOTER } }
I20260812 06:17:53.183467  2615 sys_catalog.cc:455] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [sys.catalog]: SysCatalogTable state changed. Reason: New leader 64a95902fd2040c894c51de7689308ed. Latest consensus state: current_term: 1 leader_uuid: "64a95902fd2040c894c51de7689308ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "64a95902fd2040c894c51de7689308ed" member_type: VOTER } }
I20260812 06:17:53.183615  2614 sys_catalog.cc:458] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.183636  2615 sys_catalog.cc:458] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.184141  2622 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:53.184829  2622 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:53.185050  2336 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:53.186698  2622 catalog_manager.cc:1383] Generated new cluster ID: b3fe488ce0d74a2395224f99df37bd3e
I20260812 06:17:53.186753  2622 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:53.195940  2622 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:53.196683  2622 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:53.203117  2622 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed: Generated new TSK 0
I20260812 06:17:53.203306  2622 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:53.217475  2336 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.219589  2632 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.219681  2633 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.219771  2635 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.219990  2336 server_base.cc:1061] running on GCE node
I20260812 06:17:53.220223  2336 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.220265  2336 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:53.220281  2336 hybrid_clock.cc:648] HybridClock initialized: now 1786515473220282 us; error 0 us; skew 500 ppm
I20260812 06:17:53.221233  2336 webserver.cc:533] Webserver started at http://127.2.72.1:37303/ using document root <none> and password file <none>
I20260812 06:17:53.221423  2336 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.221529  2336 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.221642  2336 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.222039  2336 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/instance:
uuid: "fda8f0bf19194f8f8f7bde4f97996477"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-1jjb"
I20260812 06:17:53.223572  2336 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:53.224613  2640 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.224898  2336 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:53.225004  2336 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root
uuid: "fda8f0bf19194f8f8f7bde4f97996477"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-1jjb"
I20260812 06:17:53.225099  2336 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:53.235281  2336 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.235674  2336 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.236018  2336 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:53.236568  2336 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:53.236635  2336 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.236691  2336 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:53.236747  2336 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.241747  2336 rpc_server.cc:307] RPC server started. Bound to: 127.2.72.1:45521
I20260812 06:17:53.243083  2715 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.72.1:45521 every 8 connection(s)
I20260812 06:17:53.254171  2716 heartbeater.cc:344] Connected to a master server at 127.2.72.62:40085
I20260812 06:17:53.254313  2716 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:53.254601  2716 heartbeater.cc:507] Master 127.2.72.62:40085 requested a full tablet report, sending...
I20260812 06:17:53.255399  2574 ts_manager.cc:194] Registered new tserver with Master: fda8f0bf19194f8f8f7bde4f97996477 (127.2.72.1:45521)
I20260812 06:17:53.256106  2336 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013473647s
I20260812 06:17:53.256202  2574 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42062
I20260812 06:17:53.263576  2574 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42064:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:53.272995  2673 tablet_service.cc:1511] Processing CreateTablet for tablet e62eaeb6034c4b2e9573060d2f2aa398 (DEFAULT_TABLE table=heavy-update-compaction-test [id=063a41d6ea7548ee8165c7672316fdca]), partition=
I20260812 06:17:53.273406  2673 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e62eaeb6034c4b2e9573060d2f2aa398. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.275885  2729 tablet_bootstrap.cc:492] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Bootstrap starting.
I20260812 06:17:53.276862  2729 tablet_bootstrap.cc:654] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.278051  2729 tablet_bootstrap.cc:492] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: No bootstrap required, opened a new log
I20260812 06:17:53.278164  2729 ts_tablet_manager.cc:1403] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:53.278692  2729 raft_consensus.cc:359] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fda8f0bf19194f8f8f7bde4f97996477" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 45521 } }
I20260812 06:17:53.278821  2729 raft_consensus.cc:385] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.278868  2729 raft_consensus.cc:740] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fda8f0bf19194f8f8f7bde4f97996477, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.279021  2729 consensus_queue.cc:260] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [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: "fda8f0bf19194f8f8f7bde4f97996477" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 45521 } }
I20260812 06:17:53.279114  2729 raft_consensus.cc:399] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.279161  2729 raft_consensus.cc:493] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.279218  2729 raft_consensus.cc:3060] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.279938  2729 raft_consensus.cc:515] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fda8f0bf19194f8f8f7bde4f97996477" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 45521 } }
I20260812 06:17:53.280140  2729 leader_election.cc:304] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [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: fda8f0bf19194f8f8f7bde4f97996477; no voters: 
I20260812 06:17:53.280350  2729 leader_election.cc:290] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.280498  2731 raft_consensus.cc:2804] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.280745  2731 raft_consensus.cc:697] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 1 LEADER]: Becoming Leader. State: Replica: fda8f0bf19194f8f8f7bde4f97996477, State: Running, Role: LEADER
I20260812 06:17:53.280763  2729 ts_tablet_manager.cc:1434] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:53.280762  2716 heartbeater.cc:499] Master 127.2.72.62:40085 was elected leader, sending a full tablet report...
I20260812 06:17:53.280905  2731 consensus_queue.cc:237] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [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: "fda8f0bf19194f8f8f7bde4f97996477" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 45521 } }
I20260812 06:17:53.282207  2574 catalog_manager.cc:5719] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 reported cstate change: term changed from 0 to 1, leader changed from <none> to fda8f0bf19194f8f8f7bde4f97996477 (127.2.72.1). New cstate: current_term: 1 leader_uuid: "fda8f0bf19194f8f8f7bde4f97996477" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fda8f0bf19194f8f8f7bde4f97996477" member_type: VOTER last_known_addr { host: "127.2.72.1" port: 45521 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:53.343189  2336 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.010s	sys 0.012s
I20260812 06:17:53.493631  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=19.054940
I20260812 06:17:53.661656  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.168s	user 0.114s	sys 0.052s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":818,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43790,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:17:53.662500  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398): free 20743880 bytes of WAL
I20260812 06:17:53.662807  2647 log_reader.cc:385] T e62eaeb6034c4b2e9573060d2f2aa398: removed 2 log segments from log reader
I20260812 06:17:53.662880  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000001 (ops 1-6)
I20260812 06:17:53.662930  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000002 (ops 7-11)
I20260812 06:17:53.667377  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:53.667742  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:53.681149  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.681595  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398): 16411393 bytes on disk
I20260812 06:17:53.681988  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.682394  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:53.837754  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.155s	user 0.095s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":488,"lbm_read_time_us":12308,"lbm_reads_lt_1ms":460,"lbm_write_time_us":27222,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":356,"threads_started":5,"update_count":2000}
I20260812 06:17:53.838362  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=10.126437
I20260812 06:17:53.891884  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.053s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19647,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:53.892436  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:53.913628  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.021s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.914135  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:54.071205  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.157s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":11808,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24705,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27008,"update_count":2000}
I20260812 06:17:54.071748  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=11.118625
I20260812 06:17:54.124348  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.052s	user 0.023s	sys 0.024s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19824,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:54.124774  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:54.135739  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4173,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.136302  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:54.146494  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.146963  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:54.335355  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.188s	user 0.101s	sys 0.077s 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":248,"lbm_read_time_us":12799,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29634,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:54.335894  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:54.387682  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.052s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23015,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.388270  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:54.400426  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.401117  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:54.566740  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.165s	user 0.088s	sys 0.065s 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":1353,"lbm_read_time_us":9990,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30727,"lbm_writes_lt_1ms":543,"mutex_wait_us":341,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:54.567391  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:54.619686  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.052s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21051,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.620385  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:54.633989  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4931,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.634734  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:54.796846  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.162s	user 0.111s	sys 0.048s 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":1110,"lbm_read_time_us":11871,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33683,"lbm_writes_lt_1ms":543,"mutex_wait_us":385,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:54.797547  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:54.848801  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.051s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20094,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.849370  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:54.861225  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.861871  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:54.891177  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1203,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1502,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":1920}
I20260812 06:17:54.891763  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398): free 115943176 bytes of WAL
I20260812 06:17:54.891995  2647 log_reader.cc:385] T e62eaeb6034c4b2e9573060d2f2aa398: removed 11 log segments from log reader
I20260812 06:17:54.892037  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000003 (ops 12-16)
I20260812 06:17:54.892067  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000004 (ops 17-21)
I20260812 06:17:54.892150  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000005 (ops 22-26)
I20260812 06:17:54.892190  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000006 (ops 27-31)
I20260812 06:17:54.892254  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000007 (ops 32-36)
I20260812 06:17:54.892282  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000008 (ops 37-41)
I20260812 06:17:54.892338  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000009 (ops 42-46)
I20260812 06:17:54.892375  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000010 (ops 47-51)
I20260812 06:17:54.892413  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000011 (ops 52-56)
I20260812 06:17:54.892452  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000012 (ops 57-61)
I20260812 06:17:54.892491  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000013 (ops 62-66)
I20260812 06:17:54.920212  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:54.920598  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398): 448 bytes on disk
I20260812 06:17:54.921113  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.921566  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=3.181125
I20260812 06:17:54.933970  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5060,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:54.934376  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:54.944177  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:54.944628  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:55.203248  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.258s	user 0.178s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":318,"lbm_read_time_us":17668,"lbm_reads_lt_1ms":774,"lbm_write_time_us":44521,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:17:55.203979  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=18.063937
I20260812 06:17:55.276770  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.073s	user 0.044s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27597,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:55.277338  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:55.289116  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4388,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.289853  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:55.518010  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.228s	user 0.137s	sys 0.091s 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":243,"lbm_read_time_us":16371,"lbm_reads_lt_1ms":672,"lbm_write_time_us":41829,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:17:55.518695  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:55.576872  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.058s	user 0.038s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23386,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.577382  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:55.588028  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.588559  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:55.784116  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.195s	user 0.117s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":395,"lbm_read_time_us":14084,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32685,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:17:55.784614  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:55.848263  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.063s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21178,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.848752  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:55.859432  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4212,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.859917  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:56.053634  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.193s	user 0.137s	sys 0.048s 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":279,"lbm_read_time_us":15814,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30658,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:17:56.054378  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:56.116441  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.062s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20248,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.116983  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:56.127777  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.128329  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:56.325332  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.197s	user 0.127s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":352,"lbm_read_time_us":14131,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30092,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:17:56.326033  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:56.371753  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.046s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20442,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.372330  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:56.382809  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.383525  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:56.424741  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.041s	user 0.035s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":283,"dirs.run_wall_time_us":1596,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2195,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:56.425419  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398): free 112239316 bytes of WAL
I20260812 06:17:56.425655  2647 log_reader.cc:385] T e62eaeb6034c4b2e9573060d2f2aa398: removed 11 log segments from log reader
I20260812 06:17:56.425700  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000014 (ops 67-71)
I20260812 06:17:56.425752  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000015 (ops 72-76)
I20260812 06:17:56.425840  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000016 (ops 77-80)
I20260812 06:17:56.425870  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000017 (ops 81-85)
I20260812 06:17:56.425908  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000018 (ops 86-90)
I20260812 06:17:56.425956  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000019 (ops 91-95)
I20260812 06:17:56.425999  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000020 (ops 96-100)
I20260812 06:17:56.426040  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000021 (ops 101-105)
I20260812 06:17:56.426079  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000022 (ops 106-110)
I20260812 06:17:56.426120  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000023 (ops 111-115)
I20260812 06:17:56.426189  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000024 (ops 116-120)
I20260812 06:17:56.452905  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:56.453336  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:56.470770  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.017s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.471232  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398): 447 bytes on disk
I20260812 06:17:56.471680  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398) 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:17:56.472256  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:56.482417  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.482888  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:56.719620  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.237s	user 0.144s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":227,"lbm_read_time_us":16938,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37217,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":63488,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:56.720381  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=18.063937
I20260812 06:17:56.786614  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.066s	user 0.038s	sys 0.016s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26185,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:56.787077  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:56.797776  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.798512  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:56.998103  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.199s	user 0.124s	sys 0.075s 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":60,"lbm_read_time_us":14354,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32862,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23424,"update_count":3000}
I20260812 06:17:56.999082  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:57.050180  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.046s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":20089,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:57.050765  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:57.075018  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.024s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5026,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.075497  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:57.090068  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.090600  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:57.311676  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.221s	user 0.147s	sys 0.073s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1053,"lbm_read_time_us":16386,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38139,"lbm_writes_lt_1ms":643,"mutex_wait_us":322,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":74496,"update_count":3000}
I20260812 06:17:57.312424  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:57.381511  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.069s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24480,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.382073  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:57.393148  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.393615  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:57.568066  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.174s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":978,"lbm_read_time_us":13078,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29323,"lbm_writes_lt_1ms":543,"mutex_wait_us":387,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:17:57.568774  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:57.626559  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.058s	user 0.039s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25777,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.627112  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:57.642827  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5865,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.643487  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:57.807111  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.163s	user 0.128s	sys 0.036s 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":214,"lbm_read_time_us":12019,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27099,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:57.807922  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=14.095187
I20260812 06:17:57.874773  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.067s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23102,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.875413  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:57.887339  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.887876  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:57.933312  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushMRSOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.045s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1668,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:57.934116  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398): free 121006604 bytes of WAL
I20260812 06:17:57.934386  2647 log_reader.cc:385] T e62eaeb6034c4b2e9573060d2f2aa398: removed 12 log segments from log reader
I20260812 06:17:57.934437  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000025 (ops 121-125)
I20260812 06:17:57.934471  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000026 (ops 126-130)
I20260812 06:17:57.934545  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000027 (ops 131-135)
I20260812 06:17:57.934583  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000028 (ops 136-140)
I20260812 06:17:57.934636  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000029 (ops 141-145)
I20260812 06:17:57.934679  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000030 (ops 146-150)
I20260812 06:17:57.934727  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000031 (ops 151-155)
I20260812 06:17:57.934777  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000032 (ops 156-160)
I20260812 06:17:57.934834  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000033 (ops 161-164)
I20260812 06:17:57.934880  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000034 (ops 165-169)
I20260812 06:17:57.934927  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000035 (ops 170-174)
I20260812 06:17:57.934973  2647 log.cc:1079] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: Deleting log segment in path: /tmp/dist-test-taskc8hFBr/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515467493850-2336-0/minicluster-data/ts-0-root/wals/e62eaeb6034c4b2e9573060d2f2aa398/wal-000000036 (ops 175-179)
I20260812 06:17:57.963040  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: LogGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:57.963490  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=3.181125
I20260812 06:17:57.987262  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.024s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4389831,"delete_count":0,"lbm_write_time_us":7350,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:17:57.987794  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:57.997831  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.010s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3775,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:57.998310  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:58.237604  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.239s	user 0.170s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":174,"lbm_read_time_us":15574,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43705,"lbm_writes_lt_1ms":743,"mutex_wait_us":27,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:17:58.238456  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398): 463 bytes on disk
I20260812 06:17:58.239069  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: UndoDeltaBlockGCOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.240033  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=18.063937
I20260812 06:17:58.297055  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.057s	user 0.035s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24815,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.297663  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=2.188937
I20260812 06:17:58.316308  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.018s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.316896  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=1.000000
I20260812 06:17:58.423499  2336 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.080s	user 1.840s	sys 0.220s
I20260812 06:17:58.473156  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: MajorDeltaCompactionOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.156s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11317,"lbm_reads_lt_1ms":660,"lbm_write_time_us":33742,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:58.473735  2717 maintenance_manager.cc:419] P fda8f0bf19194f8f8f7bde4f97996477: Scheduling FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398): perf score=10.126437
I20260812 06:17:58.491855  2336 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.068s	user 0.001s	sys 0.000s
I20260812 06:17:58.492478  2336 tablet_server.cc:179] TabletServer@127.2.72.1:0 shutting down...
I20260812 06:17:58.515892  2647 maintenance_manager.cc:643] P fda8f0bf19194f8f8f7bde4f97996477: FlushDeltaMemStoresOp(e62eaeb6034c4b2e9573060d2f2aa398) complete. Timing: real 0.042s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18292,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:58.517143  2336 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:58.517375  2336 tablet_replica.cc:333] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477: stopping tablet replica
I20260812 06:17:58.517527  2336 raft_consensus.cc:2243] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.517740  2336 raft_consensus.cc:2272] T e62eaeb6034c4b2e9573060d2f2aa398 P fda8f0bf19194f8f8f7bde4f97996477 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.521581  2336 tablet_server.cc:196] TabletServer@127.2.72.1:0 shutdown complete.
I20260812 06:17:58.528769  2336 master.cc:562] Master@127.2.72.62:40085 shutting down...
I20260812 06:17:58.533128  2336 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.533334  2336 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.533423  2336 tablet_replica.cc:333] T 00000000000000000000000000000000 P 64a95902fd2040c894c51de7689308ed: stopping tablet replica
I20260812 06:17:58.545781  2336 master.cc:584] Master@127.2.72.62:40085 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5710 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11329 ms total)

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