Long delays during boot and zpool/zfs commands on 9.1-RELEASE (possibly because of unavailable pool?)

[Henner Heck]

Hello all,

i set up a PC with FreeBSD 9.1-Release and 2 zfs pools.
One is a mirror from which FreeBSD is booting
(tough enough without getting "error 2"),
the other one a raidz2 for data.
The disks for the raidz2 are encrypted with geli and attached manually.

I noticed that a "zpool status" or a "zfs list" before attaching
the encrypted disks waits for about one minute before showing output.
When they finally do, the output is as expected, the raidz2 pool is shown as
UNAVAIL and its datasets are not listed.
When all the disks are attached with geli, the outputs are given
immediately.

On boot there are 2 delays.
One of about 1 minute after the output
"Setting hostid: 0x........"
and one of 2 minutes after
"Mounting local file systems:.".
Both these outputs don't show up in dmesg, which ends with
"Trying to mount root from zfs:zroot/ROOT []..." shortly before.

I suspect that the boot delays too are because of the encrypted pool.

A different machine running FreeBSD 8.3-RELEASE has a delay of only
about 3 seconds on "zpool status" with an encrypted pool
and also the boot shows no annoying anomalies.

Any idea how to get rid of these really long delays?


Regards,
Henner Heck



Some more info:

uname -a

FreeBSD titan 9.1-RELEASE-p3 FreeBSD 9.1-RELEASE-p3 #0: Mon Apr 29
18:27:25 UTC 2013
ro...@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC amd64

rc.conf

hostname="titan"
keymap="german.iso.kbd"
ifconfig_em0=" inet 192.168.1.21 netmask 255.255.255.0"
defaultrouter="192.168.1.1"
sshd_enable="YES"
ntpd_enable="YES"
powerd_enable="YES"
# Set dumpdev to "AUTO" to enable crash dumps, "NO" to disable
dumpdev="NO"
zfs_enable="YES"
geli_autodetach="NO"
samba_enable="YES"

loader.conf

zfs_load="YES"
vfs.root.mountfrom="zfs:zroot/ROOT"
geom_eli_load="YES"
aio_load="YES"

"zpool status" before attaching (1min delay):

pool: titanpool
state: UNAVAIL
status: One or more devices could not be opened. There are insufficient
replicas for the pool to continue functioning.
action: Attach the missing device and online it using 'zpool online'.
see: http://illumos.org/msg/ZFS-8000-3C
scan: none requested
config:

NAME STATE READ WRITE CKSUM
titanpool UNAVAIL 0 0 0
raidz2-0 UNAVAIL 0 0 0
17524249743005198207 UNAVAIL 0 0 0 was
/dev/gpt/titan01.eli
12400954011483674215 UNAVAIL 0 0 0 was
/dev/gpt/titan02.eli
4127776205786896399 UNAVAIL 0 0 0 was
/dev/gpt/titan03.eli
13439834871331336588 UNAVAIL 0 0 0 was
/dev/gpt/titan04.eli
7734910905079966692 UNAVAIL 0 0 0 was
/dev/gpt/titan05.eli
17344716162596142682 UNAVAIL 0 0 0 was
/dev/gpt/titan06.eli
11943961185890967830 UNAVAIL 0 0 0 was
/dev/gpt/titan07.eli
13738344899380447289 UNAVAIL 0 0 0 was
/dev/gpt/titan08.eli
18205195048240167252 UNAVAIL 0 0 0 was
/dev/gpt/titan09.eli
12338698010126903234 UNAVAIL 0 0 0 was
/dev/gpt/titan10.eli

pool: zroot
state: ONLINE
scan: scrub repaired 0 in 0h0m with 0 errors on Mon May 13 04:42:28 2013
config:

NAME STATE READ WRITE CKSUM
zroot ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
gpt/disk0 ONLINE 0 0 0
gpt/disk1 ONLINE 0 0 0

errors: No known data errors


"zpool status" after attaching (no delay):

pool: titanpool
state: ONLINE
scan: scrub repaired 0 in 1h35m with 0 errors on Mon May 13 06:18:22 2013
config:

NAME STATE READ WRITE CKSUM
titanpool ONLINE 0 0 0
raidz2-0 ONLINE 0 0 0
gpt/titan01.eli ONLINE 0 0 0
gpt/titan02.eli ONLINE 0 0 0
gpt/titan03.eli ONLINE 0 0 0
gpt/titan04.eli ONLINE 0 0 0
gpt/titan05.eli ONLINE 0 0 0
gpt/titan06.eli ONLINE 0 0 0
gpt/titan07.eli ONLINE 0 0 0
gpt/titan08.eli ONLINE 0 0 0
gpt/titan09.eli ONLINE 0 0 0
gpt/titan10.eli ONLINE 0 0 0

errors: No known data errors

pool: zroot
state: ONLINE
scan: scrub repaired 0 in 0h0m with 0 errors on Mon May 13 04:42:28 2013
config:

NAME STATE READ WRITE CKSUM
zroot ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
gpt/disk0 ONLINE 0 0 0
gpt/disk1 ONLINE 0 0 0

errors: No known data errors





_______________________________________________
freeb...@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-fs
To unsubscribe, send any mail to "freebsd-fs-...@freebsd.org"

[Jeremy Chadwick]

On Tue, May 14, 2013 at 08:43:21PM +0200, Henner Heck wrote:
> ...
> "Setting hostid: 0x........"
> ...

> "Mounting local file systems:.".

> Both these outputs don't show up in dmesg ...

This is normal (and has been normal since as long as I can remember):
those messages are being output by the rc(8) subsystem and being echo'd
to /dev/console.

If you want to see these messages, use the -a flag with dmesg(8).


P.S. -- When starting a new topic/thread about something, please do not
reply to an existing thread and change the subject -- this is
insufficient, and is sometimes called "thread hijacking". Some (many,
and often UNIX) mail clients use a header called In-Reply-To to
"cross-reference" mails to one another regardless of Subject. Proof of
you doing this:

171 05/12 00:21 Marc G. Fournier (0.6K) |->
172 N 05/14 20:43 Henner Heck (5.0K) | `->Long delays during boot and zpool/zfs commands on 9.
173 N 05/14 20:22 Steven Hartland (3.6K) | `->

And your mail client had this in it:

> From: Henner Heck <Henne...@web.de>
> To: freeb...@freebsd.org
> Date: Tue, 14 May 2013 20:43:21 +0200
> Subject: Long delays during boot and zpool/zfs commands on 9.1-RELEASE (possibly because of unavailable pool?)
> References: <968416157.282645.13682...@erie.cs.uoguelph.ca>
> <518EFE05...@hub.org> <518F4130...@hub.org>
> <518F4307...@hub.org>
> In-Reply-To: <518F4307...@hub.org>

So in the future actually make a new mail (new thread).

--
| Jeremy Chadwick j...@koitsu.org |
| UNIX Systems Administrator http://jdc.koitsu.org/ |
| Mountain View, CA, US |
| Making life hard for others since 1977. PGP 4BD6C0CB |

[Henner Heck]

Sorry about that, i just took a mail from the list to get the address
"freeb...@freebsd.org"
and cleaned everything up not knowing about Thunderbird setting these
headers.

[Henner Heck]

Am 14.05.2013 21:22, schrieb Steven Hartland:
> ----- Original Message ----- From: "Henner Heck" <Henne...@web.de>

>> Hello all,
>>
>> i set up a PC with FreeBSD 9.1-Release and 2 zfs pools.
>> One is a mirror from which FreeBSD is booting
>> (tough enough without getting "error 2"),
>> the other one a raidz2 for data.
>> The disks for the raidz2 are encrypted with geli and attached manually.
>>
>> I noticed that a "zpool status" or a "zfs list" before attaching
>> the encrypted disks waits for about one minute before showing output.
>> When they finally do, the output is as expected, the raidz2 pool is
>> shown as
>> UNAVAIL and its datasets are not listed.
>> When all the disks are attached with geli, the outputs are given
>> immediately.
>>
>> On boot there are 2 delays.
>> One of about 1 minute after the output
>> "Setting hostid: 0x........"
>> and one of 2 minutes after

>> "Mounting local file systems:.".

>> Both these outputs don't show up in dmesg, which ends with
>> "Trying to mount root from zfs:zroot/ROOT []..." shortly before.
>>
>> I suspect that the boot delays too are because of the encrypted pool.
>>
>> A different machine running FreeBSD 8.3-RELEASE has a delay of only
>> about 3 seconds on "zpool status" with an encrypted pool
>> and also the boot shows no annoying anomalies.
>>
>> Any idea how to get rid of these really long delays?
>

> Try the attached patch see if that helps?
>
> Regards
> Steve
>
> ================================================
> This e.mail is private and confidential between Multiplay (UK) Ltd.
> and the person or entity to whom it is addressed. In the event of
> misdirection, the recipient is prohibited from using, copying,
> printing or otherwise disseminating it or any information contained in
> it.
> In the event of misdirection, illegible or incomplete transmission
> please telephone +44 845 868 1337
> or return the E.mail to postm...@multiplay.co.uk.



Hello Steven,

i tried to apply the patch, but patch didn't return and gave no output.
I checked my the zfs.c and it doesn't seem to fit this patch.
Please see attached file.

Regards,
Henner Heck

[Freddie Cash]

On Tue, May 14, 2013 at 11:43 AM, Henner Heck <Henne...@web.de> wrote:

> I noticed that a "zpool status" or a "zfs list" before attaching
> the encrypted disks waits for about one minute before showing output.
> When they finally do, the output is as expected, the raidz2 pool is shown
> as
> UNAVAIL and its datasets are not listed.
> When all the disks are attached with geli, the outputs are given
> immediately.
>
> On boot there are 2 delays.
> One of about 1 minute after the output
> "Setting hostid: 0x........"
> and one of 2 minutes after
> "Mounting local file systems:.".
>


> Both these outputs don't show up in dmesg, which ends with
> "Trying to mount root from zfs:zroot/ROOT []..." shortly before.
>
>

"dmesg -a" will show all the messages from the boot, including the ones
from the RC scripts (like the ones above).


--
Freddie Cash
fjw...@gmail.com

[Steven Hartland]

----- Original Message -----
From: "Henner Heck" <Henne...@web.de>
To: "Steven Hartland"

> Am 14.05.2013 21:22, schrieb Steven Hartland:
>> ----- Original Message ----- From: "Henner Heck" <Henne...@web.de>
>>> Hello all,
>>>
>>> i set up a PC with FreeBSD 9.1-Release and 2 zfs pools.
>>> One is a mirror from which FreeBSD is booting
>>> (tough enough without getting "error 2"),
>>> the other one a raidz2 for data.
>>> The disks for the raidz2 are encrypted with geli and attached manually.
>>>

>>> I noticed that a "zpool status" or a "zfs list" before attaching
>>> the encrypted disks waits for about one minute before showing output.
>>> When they finally do, the output is as expected, the raidz2 pool is
>>> shown as
>>> UNAVAIL and its datasets are not listed.
>>> When all the disks are attached with geli, the outputs are given
>>> immediately.
>>>
>>> On boot there are 2 delays.
>>> One of about 1 minute after the output
>>> "Setting hostid: 0x........"
>>> and one of 2 minutes after
>>> "Mounting local file systems:.".
>>> Both these outputs don't show up in dmesg, which ends with
>>> "Trying to mount root from zfs:zroot/ROOT []..." shortly before.
>>>

>>> I suspect that the boot delays too are because of the encrypted pool.
>>>
>>> A different machine running FreeBSD 8.3-RELEASE has a delay of only
>>> about 3 seconds on "zpool status" with an encrypted pool
>>> and also the boot shows no annoying anomalies.
>>>
>>> Any idea how to get rid of these really long delays?
>>
>> Try the attached patch see if that helps?

Looks like 9.1 has been significantly changed from when I created that patch
and isn't needed any more, so not going to be that. Should have checked, sorry
for the noise.

================================================
This e.mail is private and confidential between Multiplay (UK) Ltd. and the person or entity to whom it is addressed. In the event of misdirection, the recipient is prohibited from using, copying, printing or otherwise disseminating it or any information contained in it.

In the event of misdirection, illegible or incomplete transmission please telephone +44 845 868 1337
or return the E.mail to postm...@multiplay.co.uk.

[Ronald Klop]

>> Regards
>> Steve

>>
>> ================================================
>> This e.mail is private and confidential between Multiplay (UK) Ltd.
>> and the person or entity to whom it is addressed. In the event of
>> misdirection, the recipient is prohibited from using, copying,
>> printing or otherwise disseminating it or any information contained in
>> it.
>> In the event of misdirection, illegible or incomplete transmission
>> please telephone +44 845 868 1337
>> or return the E.mail to postm...@multiplay.co.uk.
>
>
>

> Hello Steven,
>
> i tried to apply the patch, but patch didn't return and gave no output.
> I checked my the zfs.c and it doesn't seem to fit this patch.
> Please see attached file.
>
> Regards,
> Henner Heck

Sounds likes my daily wtf moment. Patch likes the patch-file on stdin.
That is why it waits forever and does not return. Ctrl-z will help that.

Use something like this:
patch < foo.diff

Regards,
Ronald.

[Henner Heck]

Always happy to give someone a special moment.
Thank you, now patch did something.
It confirmed that it is the wrong file version for the patch,
since the replacements failed and the only changes are additions.
Output:

----------------------------------------------------------------------------------------------------------
Hmm... Looks like a unified diff to me...
The text leading up to this was:
--------------------------
|--- sys/boot/zfs/zfs.c.orig 2011-10-20 18:15:29.966685430 +0000
|+++ sys/boot/zfs/zfs.c 2011-10-20 18:18:22.291033636 +0000
--------------------------
Patching file sys/boot/zfs/zfs.c using Plan A...
Hunk #1 succeeded at 47 (offset 2 lines).
Hunk #2 failed at 423.
1 out of 2 hunks failed--saving rejects to sys/boot/zfs/zfs.c.rej
Hmm... Ignoring the trailing garbage.
done
----------------------------------------------------------------------------------------------------------

I'm still hoping that someone can give the reason for the increased delays.
Since nothing actually goes wrong but just takes ages,
they might have been introduced on purpose,
not considering the possibility of a deliberately unavailable pool.(?)

Regards,
Henner Heck

[Steven Hartland]

As I mentioned in my previous response this patch is no longer needed in
9.x.

Regards
Steve

================================================
This e.mail is private and confidential between Multiplay (UK) Ltd. and the person or entity to whom it is addressed. In the event of misdirection, the recipient is prohibited from using, copying, printing or otherwise disseminating it or any information contained in it.

In the event of misdirection, illegible or incomplete transmission please telephone +44 845 868 1337
or return the E.mail to postm...@multiplay.co.uk.

[Henner Heck]

I got that, and thanks again for trying to help.
I just tried it out to show Roland that i learned
to use patch properly and his hint was not in vain. ;)

Unfortunately the initial issue remains unsolved.

Regards,
Henner Heck