3.14.0-rc3 btrfs scrub is preventing my laptop from going to sleep

This does not happen consistently, but sometimes:

PM: Preparing system for mem sleep
Freezing user space processes ...
(...)
Freezing of tasks failed after 20.002 seconds (1 tasks refusing to freeze, wq_busy=0):
btrfs D ffff88017639c800 0 12239 12224 0x00000084
ffff880165ec1960 0000000000000086 ffff880165ec1fd8 ffff88017639c2d0 00000000000141c0 ffff88017639c2d0 ffff88007b874000 ffff8804062fa480 0000000000000000 ffff880175837ec0 ffff88007b874220 ffff880165ec1970

 Call Trace:
  [<ffffffff8160b0d9>] schedule+0x73/0x75
  [<ffffffff8126e94c>] scrub_pages+0x27e/0x426
  [<ffffffff81085062>] ? finish_wait+0x65/0x65
  [<ffffffff81271732>] scrub_stripe+0xada/0xc9e
  [<ffffffff812719cc>] scrub_chunk.isra.9+0xd6/0x10d
  [<ffffffff81271c77>] scrub_enumerate_chunks+0x274/0x418
  [<ffffffff81085000>] ? finish_wait+0x3/0x65
  [<ffffffff812723bb>] btrfs_scrub_dev+0x254/0x3cb
  [<ffffffff8116ddab>] ? __mnt_want_write+0x62/0x78
  [<ffffffff81255c68>] btrfs_ioctl+0x1114/0x24b1
  [<ffffffff81140698>] ? ____cache_alloc+0x1c/0x29b
  [<ffffffff81140a06>] ? kmem_cache_alloc_node+0xef/0x179
  [<ffffffff8160d7b3>] ? _raw_spin_unlock+0x17/0x2a
  [<ffffffff81163ade>] do_vfs_ioctl+0x3d2/0x41d
  [<ffffffff8116bd00>] ? __fget+0x6f/0x79
  [<ffffffff81163b80>] SyS_ioctl+0x57/0x82
  [<ffffffff8161426d>] system_call_fastpath+0x1a/0x1f

And then I end up with a hot laptop and a mostly dead battery in my backpack.

As far as I know, this was not happening with 3.13, unless I'm doing something differently without knowing.

My laptop went to sleep just fine while I was typing this Email, so I'm guessing it's only btrfs scrub that causes the problem with sleep.

Marc

"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Some time later, I go this one, not sure if it's btrfs' fault or not:
usb 1-11: new full-speed USB device number 7 using xhci_hcd

Freezing of tasks failed after 20.006 seconds (1 tasks refusing to freeze, wq_busy=0):
laptop_mode D ffff8800048c4a80 0 6657 1 0x00000084
ffff880037f2bde0 0000000000000086 ffff880037f2bfd8 ffff8800048c4550 00000000000141c0 ffff8800048c4550 ffff8804072280e8 ffff8804072280ec ffff8800048c4550 ffff8804072280f0 00000000ffffffff ffff880037f2bdf0

Call Trace:
 [<ffffffff8160b0d9>] schedule+0x73/0x75
 [<ffffffff8160b39a>] schedule_preempt_disabled+0x18/0x24
 [<ffffffff8160bed1>] __mutex_lock_slowpath+0x158/0x1cf
 [<ffffffff8160bf5f>] mutex_lock+0x17/0x27
 [<ffffffff8146b4d0>] control_store+0x44/0xb1
 [<ffffffff814623cd>] dev_attr_store+0x18/0x24
 [<ffffffff811b1598>] sysfs_kf_write+0x3e/0x40
 [<ffffffff811b47f5>] kernfs_fop_write+0xc2/0xff
 [<ffffffff81155417>] vfs_write+0xab/0x107
 [<ffffffff81155b19>] SyS_write+0x46/0x79
 [<ffffffff8161426d>] system_call_fastpath+0x1a/0x1f

Restarting tasks ... done.

"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Hi Marc,

Could you run the following command when scrub is blocked, we can know more why scrub is blocked here.

# echo w >  /proc/sysrq-trigger
# dmesg

Thanks,
Wang

Yes, there you go:

(attached because it's too big for the list)

http://marc.merlins.org/tmp/btrfs_nofreeze.txt

Marc

"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Hi Marc,

Could you please try the following patch, and let's see if it helps:

https://patchwork.kernel.org/patch/3680431/

This patch addressed a deadlock for device replace, but i guess scrub may also trigger this problem if there are errors related to the disk.

BTW, is there some errors related to scrub device, something like:

# btrfs device stat <device>

Thanks,
Wang

I just applied your patch, along with the other btrfs send patch to 3.14.0-rc5

I didn't help with ACPI sleep. Do you have a laptop you can try this on? It'll likely be faster than me doing this remotely :)

Here's the log of failure:
http://marc.merlins.org/tmp/btrfs_nofreeze2.txt

Hope the log above helps.

You mean this?

legolas:~# btrfs scrub stat /dev/mapper/cryptroot 
scrub status for 4850ee22-bf32-4131-a841-02abdb4a5ba6
	scrub started at Sun Mar  2 20:52:21 2014, running for 1587 seconds
	total bytes scrubbed: 298.96GiB with 1 errors
	error details: csum=1
	corrected errors: 0, uncorrectable errors: 1, unverified errors: 0

Yes, I know I have an error that will flush when the older snapshots get rotated out.

I wrote a fancy cronjob that captures syslog errors as the scrub happens and tells me which file(s) created the problem.

Anyway, scrub is working fine and helping out, except for preventing S3 sleep while it's running. If you can reproduce great, but if you need me to try more patches, let me know and I'll be happy to help, even with the delay.

Thanks,
Marc

"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

#! /bin/bash

test -x /sbin/btrfs || exit 0

export PATH=/usr/local/bin:$PATH

# bash shortcut for `basename $0`
PROG=${0##*/}
lock=/var/run/$PROG

# shlock (from inn) does the right thing and grabs a lock for a dead process
# (it checks the PID in the lock file and if it's not there, it
# updates the PID with the value given to -p)
if ! shlock -p $$ -f $lock; then
    echo "$lock held, quitting" >&2
    exit
fi

if which on_ac_power >/dev/null 2>&1; then

    ON_BATTERY=0
    on_ac_power >/dev/null 2>&1 || ON_BATTERY=$?
    if [ "$ON_BATTERY" -eq 1 ]; then
	exit 0
    fi

fi

for btrfs in $(grep btrfs /proc/mounts | awk '{ print $1 }' | sort -u)
do
logger "Starting scrub of $btrfs"
tail -n 0 -f /var/log/syslog | grep "BTRFS: " | grep -Ev '(disk space caching is enabled|unlinked .* orphans|turning on discard|device label .* devid .* transid|enabling SSD mode|BTRFS: has skinny extents|BTRFS: device label)' & /sbin/btrfs scrub start -Bd $btrfs
pkill -f 'tail -n 0 -f /var/log/syslog'
logger "Ended scrub of $btrfs"
done

rm $lock

Unfortunately, i could not reproduce this problem here.

It should not be the problem that i addressed before, there is not deadlock here. try the attached patch and hopely it could solve your problem.(I know this is not polite:-) )

If the attached patch could not solve your problem, i will find a laptop and try to reproduce myself.

BTW, I suppose you should use datacow option for btrfs, but here scrub time is a little longer. (1578s for 300g).. Was your filesystem on pressure while running scrub.

Thanks,
Wang

From: Wang Shilong <[email protected]>
Date: Mon, 3 Mar 2014 14:34:07 +0800
Subject: [PATCH] Btrfs: add schedule points for scrub

---
 fs/btrfs/scrub.c | 2 ++
 1 file changed, 2 insertions(+)

index 682ec3fc..0a00db0 100644
@@ -2064,6 +2064,7 @@ leave_nomem:
 			scrub_block_put(sblock);
 			return ret;
 		}
+		cond_resched();
 	}
 
 	if (force)

@@ -2229,6 +2230,7 @@ behind_scrub_pages:
 		logical += l;
 		physical += l;
 		physical_for_dev_replace += l;
+		cond_resched();
 	}
 	return 0;
 }

1.9.0

No worries, I appreciate your help, if you can't reproduce yourself I'm happy to help.

Unfortunately that didn't help

Freezing of tasks failed after 20.007 seconds (1 tasks refusing to freeze

btrfs D ffff8803b212e900 0 15484 1 0x00000084
ffff8803b2353958 0000000000000082 ffff8803b2353fd8 ffff8803b212e3d0 00000000000141c0 ffff8803b212e3d0 ffff88040311e000 ffff8800cd098600 0000000000000000 ffff8803aa3a6740 ffff88040311e220 ffff8803b2353968

Call Trace:
 [<ffffffff8160c311>] schedule+0x73/0x75
 [<ffffffff8126eb66>] scrub_pages+0x27e/0x42b
 [<ffffffff810850c9>] ? finish_wait+0x65/0x65
 [<ffffffff81271951>] scrub_stripe+0xada/0xca3
 [<ffffffff81271bf0>] scrub_chunk.isra.9+0xd6/0x10d
 [<ffffffff81271e9a>] scrub_enumerate_chunks+0x273/0x49f
 [<ffffffff81085000>] ? prepare_to_wait_event+0xba/0xf2
 [<ffffffff81272666>] btrfs_scrub_dev+0x254/0x3cb
 [<ffffffff8116dde3>] ? __mnt_want_write+0x62/0x78
 [<ffffffff81255e82>] btrfs_ioctl+0x1114/0x24b1
 [<ffffffff81015efa>] ? paravirt_sched_clock+0x9/0xd
 [<ffffffff810164a0>] ? sched_clock+0x9/0xb
 [<ffffffff811408bd>] ? ____cache_alloc+0x23e/0x29b
 [<ffffffff81140a09>] ? kmem_cache_alloc_node+0xef/0x179
 [<ffffffff8160e9eb>] ? _raw_spin_unlock+0x17/0x2a
 [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
 [<ffffffff8116bd38>] ? __fget+0x6f/0x79
 [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
 [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f

Restarting tasks ... done.

Cheers,
Marc

"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

We probably need to put something in ->fs_freeze() to pause scrubbing (and this probably applies to snapshot deletion too) so you can hibernate. Should be easy enough to do, I'll look into it after quotas unless somebody beats me to it. Thanks,

Josef

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBAgAGBQJTFLRGAAoJEANb+wAKly3BrpsP/j2icV1uDOPGzjCwI/J3HRR2 aYy40Q1WRklCaEH0q42UOPZ7EH3I07qOv7XX0OKrgQ/UBex+EvP824HQxNsejGQI h6Pt5oH2j9xhGG3FCUzxjuN9uEbo89fIiJpJb+3YUoHkBW2w9hWBQTyQEe5DvVHA O6SZ77Zq6q0+NEjzBaxVYR9paUo0Sqs6Vyn407wsM7FYlvyJ8RWzLMgEdkSpa2v5 kXQNrv72oRAcajxwhp5LvLCHb6KyJ4DjAFt47N+ezkEJHda8AAOTYs1DJ0E/Bl0s sNL6+Uh+jZj8q61FZrO+qVmlFwd9YtnGGFQrLBPIfI8/ocp7OHLYNgc93/NAuvCk bvBtRcI4kshSa0E+qE5qxuBPC8lRjWNyK5eoPA+KqXycR6aPzqqr58ghx5RC4v71 SsU6EF9oKyZ35FFLeuE7H1sEO9jlVrk1OlbIlUDCmxNK+QY3jPmvgfvU1qJyOQZw 4NRGCg7JYn7aEWrnYWG5qEXal9wTeXgof5p0+clGmsZMcgm3D6xfbPg755e10cq1 ZPJiVqHANBEvWyK2596fJkZNmVYyE8nvuCW62HMpsJjZJZ+p2Huje8DtbGf5uN1T D5hy0NeJ0GFggxloA4CKpcBREq+uV+e584xtgsnxU4ulqWyqOiIIsVlQhE9+RXBV 7sSCnY4l24zoA2n+JOiY
=DKfb
-----END PGP SIGNATURE-----

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Ok I lied I just went ahead and did it, please let me know if this fixes it

- From 8ab47dd51e446fb2aa5dfc432c8c5b6ddd083371 Mon Sep 17 00:00:00 2001
From: Josef Bacik <[email protected]>
Date: Mon, 3 Mar 2014 12:07:11 -0500
Subject: [PATCH] Btrfs: pause scrubing when we freeze the fs

Need to make sure we don't keep scrubbing when we freeze the fs so pause it
until we are unfrozen. Thanks,

- ---

 fs/btrfs/super.c | 5 +++++
 1 file changed, 5 insertions(+)

index dc0a315..dc9ba85 100644

- --- a/fs/btrfs/super.c
+++ b/fs/btrfs/super.c
@@ -1764,6 +1764,8 @@ static int btrfs_freeze(struct super_block *sb)
struct btrfs_trans_handle *trans;
struct btrfs_root *root = btrfs_sb(sb)->tree_root;

+ btrfs_scrub_pause(root);
+
trans = btrfs_attach_transaction_barrier(root);
if (IS_ERR(trans)) {
/* no transaction, don't bother */
@@ -1776,6 +1778,9 @@ static int btrfs_freeze(struct super_block *sb)

static int btrfs_unfreeze(struct super_block *sb) {
+ struct btrfs_root *root = btrfs_sb(sb)->tree_root;
+
+ btrfs_scrub_continue(root);
return 0;
}

- --
1.8.3.1

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBAgAGBQJTFLc3AAoJEANb+wAKly3BW4EQAKasDW7tHabddmS5x3f2Vf2x rySPlP+cTszqcLTeTpeFB4rUolGOwOgZMlDLCK/q0/561uebzNTMp3khdwBCO1GA hiavMilmdnJx1uZ6PR0xW4sCI+/GsMu/gPymAgOU21wsqb7L3a2+IC9TcqX+UMML JwMn5QvqyBQ/ii9DmwHLsk+buqP0+o0wbVB//ltQKH98qn9b+AbIQEpfDT5F7xh6 5J/XEHPDFE1xJfqC7b2yTGTCyTUzUVCPzfolDGkOyZiQb4Lp/Ihn1Wh7hcW1J65z rvouCFFgaoeBkcJJDH8Dm+9qq1pqKWIw24i0GBZ+0222nncGp+qDxgydxWJ640p0 LDILxFlov5kfqqpwc6KmcLCMXU0F2wnKF6dKY31eF3zPgJs/OV2N1wg2i1ojKCr+ e4fL7dB/f/2pLE3+bQFeNVxEH1JxNkj/bK8s6V/AaIyVMODAakhMPJi/9xYQk7tl I37vr+AcMqCknvId1rZ9lDHJFJDtJCbA1PFPRdzf9OH2+RazN4vXl9xyjcoXdWZz oQz5DfGEN+fliPjDgC09DVgzFjjyXWUv49O73eEm0iIMIVHTbUovwVBcebVafr1z uugG0phhaA/gf11Q9UPwz3EHzlG+NGTmooE/Z4C5+I02z7KLDGTzGPByn7aspQOJ Sq1mfu6wwCjjA/UVK73V
=kq6N
-----END PGP SIGNATURE-----

This looked promising, but I still have the problem.

PM: Syncing filesystems ... done.
PM: Preparing system for mem sleep
Freezing user space processes ...
Freezing of tasks failed after 20.005 seconds (1 tasks refusing to freeze, wq_busy=0):
btrfs D ffff8800b9c60840 0 12711 1 0x00000084
ffff8803bc475958 0000000000000086 ffff8803bc475fd8 ffff8800b9c60310 00000000000141c0 ffff8800b9c60310 ffff8803cd8d8000 ffff8800ca31d300 0000000000000000 ffff8803b2306b40 ffff8803cd8d8220 ffff8803bc475968

Call Trace:
 [<ffffffff8160c331>] schedule+0x73/0x75
 [<ffffffff8126eb7e>] scrub_pages+0x27e/0x426
 [<ffffffff810850c9>] ? finish_wait+0x65/0x65
 [<ffffffff81271964>] scrub_stripe+0xada/0xc9e
 [<ffffffff81271bfe>] scrub_chunk.isra.9+0xd6/0x10d
 [<ffffffff81271ea8>] scrub_enumerate_chunks+0x273/0x49f
 [<ffffffff81085000>] ? prepare_to_wait_event+0xba/0xf2
 [<ffffffff81272674>] btrfs_scrub_dev+0x254/0x3cb
 [<ffffffff8116dde3>] ? __mnt_want_write+0x62/0x78
 [<ffffffff81255e9a>] btrfs_ioctl+0x1114/0x24b1
 [<ffffffff8114069b>] ? ____cache_alloc+0x1c/0x29b
 [<ffffffff81140a09>] ? kmem_cache_alloc_node+0xef/0x179
 [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
 [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
 [<ffffffff8116bd38>] ? __fget+0x6f/0x79
 [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
 [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f

I compared with the previous kernel, and it's mostly the same trace:

 [<ffffffff8160c311>] schedule+0x73/0x75
 [<ffffffff8126eb66>] scrub_pages+0x27e/0x42b
 [<ffffffff810850c9>] ? finish_wait+0x65/0x65
 [<ffffffff81271951>] scrub_stripe+0xada/0xca3
 [<ffffffff81271bf0>] scrub_chunk.isra.9+0xd6/0x10d
 [<ffffffff81271e9a>] scrub_enumerate_chunks+0x273/0x49f
 [<ffffffff81085000>] ? prepare_to_wait_event+0xba/0xf2
 [<ffffffff81272666>] btrfs_scrub_dev+0x254/0x3cb
 [<ffffffff8116dde3>] ? __mnt_want_write+0x62/0x78
 [<ffffffff81255e82>] btrfs_ioctl+0x1114/0x24b1
 [<ffffffff81015efa>] ? paravirt_sched_clock+0x9/0xd
 [<ffffffff810164a0>] ? sched_clock+0x9/0xb
 [<ffffffff811408bd>] ? ____cache_alloc+0x23e/0x29b
 [<ffffffff81140a09>] ? kmem_cache_alloc_node+0xef/0x179
 [<ffffffff8160e9eb>] ? _raw_spin_unlock+0x17/0x2a
 [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
 [<ffffffff8116bd38>] ? __fget+0x6f/0x79
 [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
 [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f

I'm not too sure why the scrub didn't stop as per your patch.

Maybe it will work if we cancel the scrub as opposed to pausing it, but of course it's not ideal.
Is that the next step?

Thanks,
Marc

"a mouse is a device used to point at the xterm you want to type in" - a.s.r.
microsoft is to operating systems ....
                                      .... what mcdonalds is to gourmet cooking
home page: http://marc.merlins.org/                         | pgp 1024r/763be901

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Sigh I thought the PM stuff called freeze_fs() but I think that was just tuxonice. I don't have a quick fix at the moment, I really will have to wait on this until after qgroups. Thanks,

Josef

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBAgAGBQJTFP+vAAoJEANb+wAKly3BT7gP/j5B5sCPycpGT282vtMjk/BU lLxIbPY3TOJgA8r5ZVBYt7glsQDk+Vct9CMqxuwT9cbgIN6wVxoj0fl40jAWsJpL 5ZNMO/dkRUZzwYiprSf9SwCZRNgjD+jTXMIl+/h9Daxajj8HJIWGovxomGpZbYKJ /Qv9GRm2emhcIstLM0t1+Fv/OSk28TiRg5VtOM60AqposqGbXEK/IfuQxBMrgT2y IUu0z+aJ2v4ykx7CHHYOLYYegfSwe/E3MZTG1KifswEi3iidiCrIstDJ2rHw7T3/ xjli3LWHb2KFRZ+gbi0lAo6cQVvGENG/jYxA8mAqTfDno7z6Xg46gCM8vT6LAfJF x4B9AUntMPJPDxiscRMkOZZE0CJhVtqdJ8QLQHguRoloS0jMXmXaF/ibH2BDB24h aacTxRQXH6XJOBRqHOp9drGMy1F69eKl+YaA3OWDVn2En83aXY+zY1acuYAGwA5H Da4WYMoiP2DiCsn4gneFmikW/oh9HkxMA81hikdrrkoOhrIIvF9iKVv/mOJcvokA 568ha9QWwS1Wwif1JLs9NUj8Ff2vrTm5g5SJKIV365nWUME63wVx6sWnRmKDButx qhJ5EMRlK3aVk+SjHDGLlzswpMZQFbC8v++J/vl6AoZuCWNetK7IyGlWcD1vCEVS eCVIHioVA1/7Kt693Gnx
=q454
-----END PGP SIGNATURE-----

That's ok, thanks for giving it a shot.

For now, I just stuck this in /etc/acpi/sleep.sh
awk '/btrfs/ { print $1 }' /proc/mounts | sort -u | while read fs; do btrfs scrub cancel $fs; done

Not great, but it ensures my laptop will go to sleep and not kill my batteries with the lid closed :)

Marc

"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901