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

ZFS process stuck at 100% CPU when receiving #5699

Closed
nfinformatique opened this issue Jan 30, 2017 · 17 comments
Closed

ZFS process stuck at 100% CPU when receiving #5699

nfinformatique opened this issue Jan 30, 2017 · 17 comments

Comments

@nfinformatique
Copy link

Hello,
First a big thanks for your work and the great functionalities you brings to linux.

System information

Type Version/Name
Distribution Name Centos
Distribution Version 7
Linux Kernel 3.10.0-327.10.1.el7.x86_64
Architecture x86_64
ZFS Version 0.6.5.6-1
SPL Version 0.6.5.6-1

Describe the problem you're observing

When receiving a stream, the zfs process stucks at 100%, for weeks (waited more than 24 days), without any errors on dmesg/messages/tty. I tried receiving with the 0.6.5.8, same happens. I tried on FreeBSD 9.3, same happens. I can use zfs on other pools/fs, but no way to kill the zfs process, in R state.
Tried with and without selinux, no difference.
Tried to export the source dataset again, same result.

Describe how to reproduce the problem

I exported a jail created by FreeNAS, and imported with -udv.

Main question: does any special file attribute in the unmounted data receiving operation can lead to this situation ?
Second question: is there any way to receive the other datasets in the stream ? I tried to manually create a local dataset with the same name, but any failure will stop receiving, ignoring the subsequents datasets.

Include any warning/errors/backtraces from the system logs

The strace result:

...
write(1, "received 0B stream in 1 seconds "..., 41) = 41
ioctl(3, 0x5a12, 0x7fff3b5a0870)        = 0
read(0, "\0\0\0\0\0\0\0\0\254\313\272\365\2\0\0\0\21\0\0\0\0\0\0\0\356\330lX\0\0\0\0"..., 312) = 312
read(0, "", 0)                          = 0
ioctl(3, 0x5a12, 0x7fff3b5a0870)        = 0
ioctl(3, 0x5a12, 0x7fff3b5a0870)        = -1 ENOENT (No such file or directory)
ioctl(3, 0x5a12, 0x7fff3b5a0420)        = 0
ioctl(3, 0x5a12, 0x7fff3b5a0860)        = 0
write(1, "receiving full stream of backup/"..., 123) = 123
ioctl(3, 0x5a1b

Stops there....

@loli10K
Copy link
Contributor

loli10K commented Jan 30, 2017

When receiving a stream, the zfs process stucks at 100%, for weeks (waited more than 24 days), without any errors on dmesg/messages/tty.

@nfinformatique which version of FreeNAS is/was used to generate the stream? IIRC a similar problem has been reported to the illumos-discuss mailing list (title "ZFS recv hangs"). Can you pipe the stream through zstreamdump and grep for "FREEOBJECTS"?

@nfinformatique
Copy link
Author

FreeNAS: FreeBSD HOSTNAME 10.3-STABLE FreeBSD 10.3-STABLE
cat stream | zstreamdump | grep FREEOBJECTS
Total DRR_FREEOBJECTS records = 4

@nfinformatique
Copy link
Author

The full stream dump information (it is a full send, no increment)

BEGIN record
        hdrtype = 1
        features = 30007
        magic = 2f5bacbac
        creation_time = 586cd8ee
        type = 2
        flags = 0x4
        toguid = d82dd66022fb32f3
        fromguid = 0
        toname = backup/jails/.XXX@clean
END checksum = 89615b28a8fa539/1c0f0949fe8388e6/5aec4c0ad9c876bf/4daa1504ad6ff08b
SUMMARY:
        Total DRR_BEGIN records = 1
        Total DRR_END records = 1
        Total DRR_OBJECT records = 258577
        Total DRR_FREEOBJECTS records = 4
        Total DRR_WRITE records = 215675
        Total DRR_WRITE_BYREF records = 8830
        Total DRR_WRITE_EMBEDDED records = 39090
        Total DRR_FREE records = 262463
        Total DRR_SPILL records = 0
        Total records = 784641
        Total write size = 1982718464 (0x762de200)
        Total stream length = 2274396968 (0x87908b28)

@loli10K
Copy link
Contributor

loli10K commented Jan 30, 2017

@nfinformatique It would seems that the stable branch of freebsd10 did indeed get OpenZFS 6393 (zfs receive a full send as a clone):
https://github.com/freenas/os/commits/freebsd10-stable/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_send.c

Try again with zstreamdump -v, look for something like:

FREEOBJECTS firstobj = $some_number numobjs = $huge_number_here

@nfinformatique
Copy link
Author

Indeed, there is such huge number of free objects.
cat stream | zstreamdump -v | grep FREEOBJECTS

FREEOBJECTS firstobj = 0 numobjs = 1
FREEOBJECTS firstobj = 258578 numobjs = 14
FREEOBJECTS firstobj = 258592 numobjs = 36028797018705376
FREEOBJECTS firstobj = 0 numobjs = 0
        Total DRR_FREEOBJECTS records = 4

Thank you very much for your help. I will manage to get a local up-to-date version to import properly.

@nfinformatique
Copy link
Author

I installed a temporary Ubuntu and compiled the last module (0.7.0-rc3), did a send/receive and it worked !
Thanks for saving my week !

@gmelikov
Copy link
Member

@nfinformatique feel free to open the issue if you need. Closed.

@loli10K
Copy link
Contributor

loli10K commented Jan 30, 2017

@nfinformatique keep in mind that 0.7.0 is not recommended for production use yet.

Alternatively you'll want to send the data without freeobjects records, but you'll need OpenZFS 6536 (zfs send: want a way to disable setting of DRR_FLAG_FREERECORDS) for that, which i could only find in freebsd11 truenas/os@d29ea66.

@Fabian-Gruenbichler
Copy link
Contributor

seems like updating to the freenas 9.10 nightlies (which are based on freebsd11 and should have 6536) and setting the tunable to 0 does not help.

at least, I still get a stream with a huge FREEOBJECTS record which hangs zfs recv under ZoL 0.6.5.9..

@nfinformatique
Copy link
Author

nfinformatique commented Mar 31, 2017 via email

@loli10K
Copy link
Contributor

loli10K commented Mar 31, 2017

@Fabian-Gruenbichler i'm reading again the original issue, maybe the second part of the request was not implemented? The title was also changed from "zfs send: want a way to disable sending of free records" to "zfs send: want a way to disable setting of DRR_FLAG_FREERECORDS".

It seems that it might also be desireable to have support for generating streams without free records for other reasons, such as in cases where we definitely know that the receiving end is not receiving the stream as a clone. An example of this might be when using some kind of automatic replication process. I propose that we add a new option to zfs send (-F) that turns off sending of free records.

It that's the case you have to use pre- OpenZFS 6393 version to send the stream: sorry about that.

@zviratko
Copy link

zviratko commented Aug 2, 2017

I just hit this issue as well.
What is the fix for this?
I upgraded the sending side to 0.7.0 and re-run zfs send/receive and now I have two zfs receive processes stuck on my storage. I can't upgrade the receiving side.

Is there anything to at least kill those processes? Will they ever finish?

@nfinformatique
Copy link
Author

nfinformatique commented Aug 2, 2017 via email

Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems.the problematic records of the following kind now no longer lead
to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems.the problematic records of the following kind now no longer lead
to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: refs/heads/spl-0.6.5-release
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: 'refs/heads/spl-0.6.5-release'
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: 3010774dd6ad6e6eb1f6a4d9c603dd49c55c79c9
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: spl-0.6.5-release
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: spl-0\.6\.5-release
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: "spl-0.6.5-release"
Signed-off-by: Fabian Grünbichler <[email protected]>
Fabian-Gruenbichler added a commit to Fabian-Gruenbichler/zfs that referenced this issue Sep 5, 2017
this combines changes from

e6d3a84

    OpenZFS 6393 - zfs receive a full send as a clone

and

50c957f

    Implement large_dnode pool feature

to hopefully allow sending regular streams from 0.7.x to 0.6.5.x based
systems. the problematic records of the following kind now no longer
lead to an infinite loop, but instead allow the receive to complete:

drr_type = FREEOBJECTS firstobj = 64 numobjs = 36028797018963904 err = 0

see issues openzfs#5699 (older incompatibility between FreeNAS and <= 0.6.5.11)
and openzfs#6507 (recent incompatibility between 0.7.x and <= 0.6.5.11)

Signed-off-by: Fabian Grünbichler <[email protected]>
Requires-spl: refs/pull/647/head
@zviratko
Copy link

zviratko commented Sep 8, 2017

FYI a pool I created with 0.7.0 to get around this issue got into problems when run with 0.6.5.9 and 0.6.5.11 afterwards where it was not freeing space. (not even upgrading to 0.7.1 fixed it)
The obvious fix - do a zfs send/receive.

but

local zfs send/receive of the offending pool results in zfs recv stuck like before

Not sure if this was "expected", I did not expect it

Applying this patch on top of 0.6.5.11 fixed it (or at least it got further and is still running)
397f816

@nfinformatique
Copy link
Author

nfinformatique commented Sep 8, 2017 via email

behlendorf pushed a commit that referenced this issue Oct 10, 2017
All objects after the last written or freed object are not supposed to
exist after receiving the stream.  Free them accordingly, as if a
freeobjects record for them had been included in the stream.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes #5699
Closes #6507
Closes #6616
behlendorf pushed a commit that referenced this issue Oct 10, 2017
When sending an incremental stream based on a snapshot, the receiving
side must have the same base snapshot.  Thus we do not need to send
FREEOBJECTS records for any objects past the maximum one which exists
locally.

This allows us to send incremental streams (again) to older ZFS
implementations (e.g. ZoL < 0.7) which actually try to free all objects
in a FREEOBJECTS record, instead of bailing out early.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes #5699
Closes #6507
Closes #6616
aerusso pushed a commit to aerusso/zfs that referenced this issue Oct 11, 2017
All objects after the last written or freed object are not supposed to
exist after receiving the stream.  Free them accordingly, as if a
freeobjects record for them had been included in the stream.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes openzfs#5699
Closes openzfs#6507
Closes openzfs#6616
aerusso pushed a commit to aerusso/zfs that referenced this issue Oct 11, 2017
When sending an incremental stream based on a snapshot, the receiving
side must have the same base snapshot.  Thus we do not need to send
FREEOBJECTS records for any objects past the maximum one which exists
locally.

This allows us to send incremental streams (again) to older ZFS
implementations (e.g. ZoL < 0.7) which actually try to free all objects
in a FREEOBJECTS record, instead of bailing out early.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes openzfs#5699
Closes openzfs#6507
Closes openzfs#6616
aerusso pushed a commit to aerusso/zfs that referenced this issue Oct 12, 2017
All objects after the last written or freed object are not supposed to
exist after receiving the stream.  Free them accordingly, as if a
freeobjects record for them had been included in the stream.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes openzfs#5699
Closes openzfs#6507
Closes openzfs#6616
aerusso pushed a commit to aerusso/zfs that referenced this issue Oct 12, 2017
When sending an incremental stream based on a snapshot, the receiving
side must have the same base snapshot.  Thus we do not need to send
FREEOBJECTS records for any objects past the maximum one which exists
locally.

This allows us to send incremental streams (again) to older ZFS
implementations (e.g. ZoL < 0.7) which actually try to free all objects
in a FREEOBJECTS record, instead of bailing out early.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes openzfs#5699
Closes openzfs#6507
Closes openzfs#6616
tonyhutter pushed a commit that referenced this issue Oct 16, 2017
All objects after the last written or freed object are not supposed to
exist after receiving the stream.  Free them accordingly, as if a
freeobjects record for them had been included in the stream.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes #5699
Closes #6507
Closes #6616
tonyhutter pushed a commit that referenced this issue Oct 16, 2017
When sending an incremental stream based on a snapshot, the receiving
side must have the same base snapshot.  Thus we do not need to send
FREEOBJECTS records for any objects past the maximum one which exists
locally.

This allows us to send incremental streams (again) to older ZFS
implementations (e.g. ZoL < 0.7) which actually try to free all objects
in a FREEOBJECTS record, instead of bailing out early.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes #5699
Closes #6507
Closes #6616
@cjlee112
Copy link

Argh, I just ran into this same bug, when doing incremental snapshot send/receive on a Mint 18.1 server (running an older 0.6 version of ZFS), reading from a zpool created on a Mint 19 box (using a newer 0.7 version of ZFS). The ZFS receive process hung with 100% CPU usage, and could not be killed even with signal 9. The only way to get out of this was to reboot the server.

MORAL: on hosts with older versions of ZFS, do not try to read zpools created by newer versions of ZFS.

@nfinformatique
Copy link
Author

nfinformatique commented Aug 30, 2018 via email

FransUrbo pushed a commit to FransUrbo/zfs that referenced this issue Apr 28, 2019
All objects after the last written or freed object are not supposed to
exist after receiving the stream.  Free them accordingly, as if a
freeobjects record for them had been included in the stream.

Reviewed by: Paul Dagnelie <[email protected]>
Reviewed-by: Brian Behlendorf <[email protected]>
Signed-off-by: Fabian Grünbichler <[email protected]>
Closes openzfs#5699
Closes openzfs#6507
Closes openzfs#6616
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants