Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

recv_fix_encryption_hierarchy does horrifically inefficient lookups that could be either cached or refactored, and it bottlenecks super badly #16317

Open
trentbuck opened this issue Jul 1, 2024 · 2 comments · May be fixed by #16929
Labels
Type: Defect Incorrect behavior (e.g. crash, hang)

Comments

@trentbuck
Copy link

System information

Type Version/Name
Distribution Name Debian
Distribution Version Debian 12 Bookworm
Kernel Version 6.7.12+bpo-cloud-amd64 (also 6.7.12+bpo-amd64)
Architecture amd64
OpenZFS Version 2.2.4-1~bpo12+1 (also 2.2.3-2~bpo12+1)

Describe the problem you're observing

When doing a zfs send/recv with encryption and replication, zfs send completes after about 15 minutes, but zfs send then spends another 825 minutes using 100% of 1 CPU core.

In my test recipe, "zfs send" takes 20 seconds and generates an 18MB blob, and "zfs receive" takes 2580 seconds.

The issue appears to be proportional to the number of datasets.
On a system with ~100 datasets, it is not noticeable.
I asked #openzfs (IRC) for help with this, and someone there worked out which function was causing the problem (the issue title is what they suggested).

Describe how to reproduce the problem

Here is a minimal recipe that demonstrates the time difference.

#!/bin/sh -vex                                                                                                                                                                                                       

# PROBLEM: when I do "zfs send | ssh backup-server zfs recv",                                                                                                                                                        
#          I see that "zfs send" finishes after about 15 minutes, but                                                                                                                                                
#          "zfs recv" on the remote host consumes 100% of one CPU core for 10 HOURS.                                                                                                                                 
#          It does eventually exit.                                                                                                                                                                                  
#                                                                                                                                                                                                                    
#          The delay appears to be proportional to the number of datasets in the pool, so                                                                                                                            
#          on a system with 10 users, I didn't notice the problem, but                                                                                                                                               
#          on a system with 1000 users, I noticed right away!                                                                                                                                                        
#          (On both systems, there are separate datasets for each user's $HOME and $MAIL.)                                                                                                                           
#                                                                                                                                                                                                                    
# 05:01 <PMT> it's pretty simple, just, "recv_fix_encryption_hierarchy does horrifically inefficient lookups that could be either cached or refactored, and it bottlenecks super badly"                              

# Report what we're running.                                                                                                                                                                                         
zfs --version
uname -a

# First clean up anything from a previous attempt.                                                                                                                                                                   
zpool export A || :
rm -f /A.vdev

# Make a new pool with 1000 datasets in it.                                                                                                                                                                          
truncate -s1T /A.vdev
zpool create -O canmount=off -O mountpoint=none A /A.vdev
python3 -c 'print(open("/dev/urandom", "rb").read(32).hex(),file=open("/A.passphrase", "w"))'
zfs create -v -o encryption=on -o keyformat=hex -o keylocation=file:///A.passphrase A/A
seq 100 999 >/A.txt
time xargs --arg-file=/A.txt -I N zfs create -v A/A/N

# Make a snapshot and then send it to ourselves.                                                                                                                                                                     
# Normally this would be a pipeline "zfs send ⋯ A/A@1 | ssh B zfs recv ⋯ B/A", but                                                                                                                                   
# use a temporary file so we can clearly see how long each step takes.                                                                                                                                               
zfs snapshot -r A/A@1
>/[email protected] time zfs send --large-block --embed --compressed --raw --replicate A/A@1
</[email protected] time zfs receive -v -o readonly=on -o canmount=noauto A/B

# This happens with incrementals also.                                                                                                                                                                               
zfs snapshot -r A/A@2
>/[email protected] time zfs send --large-block --embed --compressed --raw --replicate -I 1 A/A@2
</[email protected] time zfs receive -v -o readonly=on -o canmount=noauto -F A/B

The output is:
zfs.recv_fix_encryption_hierarchy.txt

Include any warning/errors/backtraces from the system logs

No errors --- the zfs receive process does eventually terminate, it's just very very slow.

@trentbuck trentbuck added the Type: Defect Incorrect behavior (e.g. crash, hang) label Jul 1, 2024
@rincebrain
Copy link
Contributor

rincebrain commented Jul 1, 2024

tl;dr I'm pretty sure just adding a caching layer for lookups in recv_fix_encryption_hierarchy would make this take O(free), since it basically spends forever ioctling on zfs list/get iteration, when the equivalent of just doing an enormous "get" or "list" once and using that data should suffice. (You'd have racing issues, in some sense, perhaps, but since you're not preventing people changing anything in the receive hierarchy or around it under you anyway, that's still true either way, I think...)

(In slightly more words - if I follow the code correctly, that function basically does "for dataset in datasets, if encrypted, go walk up and down each direction trying to find the 'closest' 'parent' for the encryptionroot", and since each of those checks is an ioctl, if you start nesting nontrivial numbers of datasets at each layer, you get sad.)

@gamanakis gamanakis linked a pull request Jan 5, 2025 that will close this issue
13 tasks
@gamanakis
Copy link
Contributor

I was hitting this lately and decided to give it a go. Thank you @rincebrain and @trentbuck for reporting and digging into it. I just marked #16929 as ready for review. Would you mind taking a look at it?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Type: Defect Incorrect behavior (e.g. crash, hang)
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants