Re: Proposal: Disable compression of newsyslog by default

[Fabian Keil]

Xin Li  wrote on 2023-12-22 at 23:18:23:

> Inspired by D42961, I propose that we move forward with disabling the 
> compression by default in newsyslog, as implemented in 
> https://reviews.freebsd.org/D43169
[...]
> Therefore I would propose that we change the default compression setting 
> to "none" in FreeBSD 15.0.  This change reflects our adaptation to the 
> evolving technological environment and user needs.  It also aligns with 
> the broader initiative to modernize our systems while maintaining 
> flexibility and efficiency.
> 
> I look forward to your thoughts and feedback on this proposal.

In ElectroBSD I simply removed the J flags in newsyslog.conf in 2021 [0].

I have no strong feelings about it, but it's unclear to me
why newsyslog[8] itself needs to be changed.

Fabian

[0] 

Re: 1 year src-patch anniversary!

[Fabian Keil]

Mateusz Guzik  wrote on 2023-01-29 at 23:29:48:

> On 1/29/23, Jamie Landeg-Jones  wrote:
> > https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=261657 is a trivial fix
> > to an admittedly trivial issue, but it's soon going to hit one year old,
> > and has not had any feedback. Not even "this is rubbish. close ticket"
> >
> > | jamie@catwalk:~ % stat 'so good they named it twice'
> > | stat: so good they named it twice: stat: No such file or directory
> >
> > As such, it's the oldest of my patches to be completely ignored, but then,
> > most of my fixes I haven't even submitted, because, what's the point?
> > I've instead spent time writing something so the patches are automatically
> > aplied to my src tree, and distributed to all my servers.
> >
> > I know it's a volunteer effort, but I've been here 25 years, and whilst
> > I could (and should) take on more port-maintainership, any other offers
> > of help have fallen on deaf ears.
> >
> 
> Well I was not aware of it.
> 
> mail me with git format-patch result and I'll commit.

Is this an open invitation?

I can easily beat the 1 year anniversary with a couple of
ggate-related patches:


Teaser:
fk@t520 /usr/src $grep "^Reported" 
~/web/www.fabiankeil.de/sourcecode/electrobsd/ElectroBSD-13-f5631983b23-2023.02.02-ggate.diff
 
Reported to security-offi...@freebsd.org on 2014-12-09.
Reported to security-offi...@freebsd.org on 2014-12-09.
Reported to security-offi...@freebsd.org on 2014-12-09.
Reported to security-offi...@freebsd.org on 2014-12-09.
Reported to security-offi...@freebsd.org on 2014-12-09.
Reported to security-offi...@freebsd.org on 2015-04-05.
Reported to security-offi...@freebsd.org on 2015-04-05.
Reported to security-offi...@freebsd.org on 2015-04-05.

The patch set is against stable/13 but I could rebase
on HEAD if there's interest and actual merge conflicts.

Fabian


pgpt_qYb_IBR8.pgp
Description: OpenPGP digital signature

Re: Ordering of files in zoneinfo

[Fabian Keil]

Xin LI  wrote:

> I have took a look at the change history, it seems that the find
> operation was introduced in r245265
>  (brooks@,
> to support packaged base) and sort was initially implemented as find -s
> in r289451
>  (ngie@,
> to make METALOG reproducible) then as sort in r328958
>  (imp@,
> for portability).
> 
> I wonder if we could drop the sort and replace ${TZS} in line 100 with
> ${TZS:O} instead?

Makes sense to me.
 
> By the way, looking at
> https://github.com/freebsd/pkg/blob/master/libpkg/metalog.c , I wonder if
> the sort should really happen in pkg(8) instead?

Currently the METALOG is also used when creating the tarballs so sorting
only in pkg would be insufficient as long as tarballs are still supported.

Fabian
___
freebsd-current@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-current
To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"

Re: ZFS - Abyssal slow on copying

[Fabian Keil]

"O. Hartmann"  wrote:

> Running 12-CURRENT (FreeBSD 12.0-CURRENT #32 r306579: Sun Oct  2 09:34:50 
> CEST 2016 ), I
> have a NanoBSD setup which creates an image for a router device.
> 
> The problem I face is related to ZFS. The system has a system's SSD (Samsung 
> 850 Pro,
> 256GB) which has an UFS filesystem. Aditionally, I have also a backup and a 
> data HDD,
> both WD, one 3 TB WD RED Pro, on 4 TB WD RED (the backup device). Both the 
> sources for
> the NanoBSD and the object tree as well as the NANO_WORLDDIR are residing on 
> the 3 TB
> data drive. 
> 
> The box itself has 8 GB RAM. When it comes to create the memory disk, which 
> is ~ 1,3 GB
> in size, the NanoBSD script starts creating the memory disk and then 
> installing world
> into this memory disk. And this part is a kind of abyssal in terms of the 
> speed.

Can you reproduce the issue if you replace the memory disk with
a zvol or tmpfs?

While I agree that depulication could be the cause of the problem,
it probably wouldn't hurt to rule out a memory-disk related issue
before recreating the pool.

Fabian


pgph6o96DoQK7.pgp
Description: OpenPGP digital signature

Re: how to recycle Inact memory more aggressively?

[Fabian Keil]

Gary Jennejohn  wrote:

> In the course of the last year or so the behavior of the vm system
> has changed in regard to how aggressively Inact memory is recycled.
> 
> My box has 8GB of memory.  At the moment I'm copying 100s of gigabytes
> from one file system to another one.
> 
> Looking at top I observe that there are about 6GB of Inact memory.
> This value hardly changes.  Instead of aggressively recycling the
> Inact memory the vm now seems to prefer to swap.

Are you using ZFS?

> Last year, can't rmember excatly when, the behavior was totally
> different.  The vm very aggessively recycled Inact memory and,
> even when copying 100s of GB of files, the system hardly swapped.
> 
> It seems rather strange to me that the vm happily allows gigbytes
> of Inact memory to be present and prefers swapping to recyclincg.
>
> Are there any sysctl's I can set to get the old behavior back?

I don't think so.

I'm currently using this patch set to work around the issue:
https://www.fabiankeil.de/sourcecode/electrobsd/vm-limit-inactive-memory-more-aggressively.diff

Patch 4 adds a couple of sysctls that can be used to let the ZFS
ARC indirectly put pressure on the inactive memory until a given
target is reached.

Fabian


pgpM814FgDXE8.pgp
Description: OpenPGP digital signature

Re: panic: devfs_fsync: vop_stdfsync failed.

[Fabian Keil]

Fabian Keil <freebsd-lis...@fabiankeil.de> wrote:

> I got the following panic by impatiently unplugging a device while a
> msdosfs partition on it was in the process of getting unmounted:
> 
> Unread portion of the kernel message buffer:
> [368] Device IPOD went missing before all of the data could be written to it; 
> expect data loss.
> [368] fsync: giving up on dirty
> [368] 0xf80011b24760: tag devfs, type VCHR
> [368] usecount 1, writecount 0, refcount 4770 mountedhere 
> 0xf800061eb200
> [368] flags (VI_DOOMED|VI_ACTIVE)
> [368] v_object 0xf80011a4c500 ref 0 pages 4782 cleanbuf 4766 dirtybuf 
> 1
> [368] lock type devfs: EXCL by thread 0xf80010c424d0 (pid 40394, 
> sudo, tid 101528)
> [368] dev msdosfs/IPOD
> [368] panic: devfs_fsync: vop_stdfsync failed.

Filed as bug #205515: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=205515

Fabian


pgpz42ZqSWP1P.pgp
Description: OpenPGP digital signature

Re: fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

Fabian Keil <freebsd-lis...@fabiankeil.de> wrote:

> Konstantin Belousov <kostik...@gmail.com> wrote:
> 
> > On Wed, Dec 16, 2015 at 04:09:17PM +0100, Fabian Keil wrote:  
> > > Thanks. I'm currently testing the patch on three systems but it may take 
> > > a while ...
> > > 
> > 
> > Better use mjg' patch with the small adjustment.  I put it below.  
> 
> Will do.

Several million forks later the systems remain stable.

Fabian


pgpw0NeXyMOPB.pgp
Description: OpenPGP digital signature

Re: fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

Konstantin Belousov <kostik...@gmail.com> wrote:

> On Wed, Dec 16, 2015 at 04:09:17PM +0100, Fabian Keil wrote:
> > Thanks. I'm currently testing the patch on three systems but it may take a 
> > while ...
> >   
> 
> Better use mjg' patch with the small adjustment.  I put it below.

Will do.

Fabian


pgpARhuAh6qDb.pgp
Description: OpenPGP digital signature

Re: fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

Oliver Pinter  wrote:

> Is this with latest 11-CURRENT or 10-STABLE?
> 
> Or contains the ad578c311ef commit?

The panic is from a system based on 11-CURRENT r290926.

Is ad578c311ef a HardenedBSD commit? It doesn't seem to
exist in https://github.com/freebsd/freebsd.git.

Fabian


pgpHRlok72ddQ.pgp
Description: OpenPGP digital signature

Re: fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

Konstantin Belousov <kostik...@gmail.com> wrote:

> On Tue, Dec 15, 2015 at 05:42:38PM +0100, Fabian Keil wrote:
> > I've seen the following panic a couple of times in the last three
> > months, usually while poudriere was running and with sh being the
> > current process.
> > 
> > This one is from a system based on r290926 running with
> > kern.randompid=9001 and forking frequently (>1000 forks/second)
> > due to poudriere and afl-fuzz:
> > 
> > Fatal trap 12: page fault while in kernel mode
> > cpuid = 1; apic id = 04
> > fault virtual address   = 0x618b00a8
> > fault code  = supervisor read data, page not present
> > instruction pointer = 0x20:0x80909158
> > stack pointer   = 0x28:0xfe011e03b940
> > frame pointer   = 0x28:0xfe011e03b960
> > code segment= base 0x0, limit 0xf, type 0x1b
> > = DPL 0, pres 1, long 1, def32 0, gran 1
> > processor eflags= interrupt enabled, resume, IOPL = 0
> > current process = 71325 (sh)
> > trap number = 12
> > panic: page fault
> > cpuid = 1
> > KDB: stack backtrace:
> > [...]
> > Uptime: 13d20h43m20s
> > [...]
> > (kgdb) where
> > #0  doadump (textdump=1) at pcpu.h:221
> > #1  0x8094a923 in kern_reboot (howto=260) at 
> > /usr/src/sys/kern/kern_shutdown.c:364
> > #2  0x8094ae8b in vpanic (fmt=, ap= > optimized out>) at /usr/src/sys/kern/kern_shutdown.c:757
> > #3  0x8094acc3 in panic (fmt=0x0) at 
> > /usr/src/sys/kern/kern_shutdown.c:688
> > #4  0x80c2fbb1 in trap_fatal (frame=, 
> > eva=) at /usr/src/sys/amd64/amd64/trap.c:834
> > #5  0x80c2fda4 in trap_pfault (frame=0xfe011e03b890, 
> > usermode=) at /usr/src/sys/amd64/amd64/trap.c:684
> > #6  0x80c2f55e in trap (frame=0xfe011e03b890) at 
> > /usr/src/sys/amd64/amd64/trap.c:435
> > #7  0x80c120a7 in calltrap () at 
> > /usr/src/sys/amd64/amd64/exception.S:234
> > #8  0x80909158 in fork_findpid (flags=) at 
> > /usr/src/sys/kern/kern_fork.c:281  
> It is the values of *p and *(p->p_pgrp) that are needed, from the frame 8.

Unfortunately it's not available and apparently I removed the attempts
to get it from the previous output.

#8  0x80909158 in fork_findpid (flags=) at 
/usr/src/sys/kern/kern_fork.c:281
warning: Source file is more recent than executable.

281 (p->p_pgrp != NULL &&
Current language:  auto; currently minimal
(kgdb) p p
No symbol "p" in current context.
(kgdb)  p trypid
$1 = 
(kgdb)  p pidchecked
$2 = 9
(kgdb) p lastpid
$3 = 51281

allproc is available and the first one matches lastpid and has an invalid
p_pgrp, but due to trypid being optimized out as well, it's not obvious
(to me) that it's the right process.

(kgdb)  p *allproc->lh_first
$4 = {p_list = {le_next = 0xf800a99e4548, le_prev = 0x813f3cc8}, 
p_threads = {tqh_first = 0xf801162819a0, tqh_last = 0xf801162819b0}, 
p_slock = {lock_object = {
  lo_name = 0x80e22449 "process slock", lo_flags = 537067520, 
lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, p_ucred = 0xf8009d07, 
p_fd = 0x0, p_fdtol = 0x0, p_stats = 0xf800299e5800, 
  p_limit = 0x0, p_limco = {c_links = {le = {le_next = 0x0, le_prev = 0x0}, sle 
= {sle_next = 0x0}, tqe = {tqe_next = 0x0, tqe_prev = 0x0}}, c_time = 0, 
c_precision = 0, c_arg = 0x0, c_func = 0, 
c_lock = 0xf800304df120, c_flags = 0, c_iflags = 0, c_cpu = 0}, 
p_sigacts = 0x0, p_flag = 268443648, p_flag2 = 0, p_state = PRS_NEW, p_pid = 
51281, p_hash = {le_next = 0x0, 
le_prev = 0xfec8a288}, p_pglist = {le_next = 0x0, le_prev = 
0xf800aa94d618}, p_pptr = 0xf800aa94d548, p_sibling = {le_next = 0x0, 
le_prev = 0xf800aa94d640}, p_children = {
lh_first = 0x0}, p_reaper = 0xf800029a5548, p_reaplist = {lh_first = 
0x0}, p_reapsibling = {le_next = 0xf8007e713548, le_prev = 
0xf80023df1110}, p_mtx = {lock_object = {
  lo_name = 0x80e2243c "process lock", lo_flags = 558039040, 
lo_data = 0, lo_witness = 0x0}, mtx_lock = 18446735280470265856}, p_statmtx = 
{lock_object = {lo_name = 0x80e22457 "pstatl", 
  lo_flags = 537067520, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, 
p_itimmtx = {lock_object = {lo_name = 0x80e2245e "pitiml", lo_flags = 
537067520, lo_data = 0, lo_witness = 0x0}, 
mtx_lock = 4}, p_profmtx = {lock_object = {lo_name = 0x80e22465 
"pprofl", lo_flags = 537067520, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, 
p_ksi = 0xf80126950380, p_sigqueue = {
sq_signals = {__bits = 0xf800304df1a8}

Re: fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

Oliver Pinter  wrote:

> Yes, it's a HardenedBSD commit. Currently only a workaround, because I have
> now lesser time for the real fix in this month.
> 
> Are you running on ZFS?

Yes.

Fabian


pgpuOBy_BlV8u.pgp
Description: OpenPGP digital signature

Re: fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

Konstantin Belousov <kostik...@gmail.com> wrote:

> On Wed, Dec 16, 2015 at 12:21:16PM +0100, Fabian Keil wrote:
> > Konstantin Belousov <kostik...@gmail.com> wrote:  
> > > It is the values of *p and *(p->p_pgrp) that are needed, from the frame 
> > > 8.  
> > 
> > Unfortunately it's not available and apparently I removed the attempts
> > to get it from the previous output.  
> 
> > allproc is available and the first one matches lastpid and has an invalid
> > p_pgrp, but due to trypid being optimized out as well, it's not obvious
> > (to me) that it's the right process.  
> 
> p_suspcount = 0, p_xthread = 0xf801162819a0, p_boundary_count = 0, 
> p_pendingcnt = 0, p_itimers = 0x0, p_procdesc = 0x0, p_treeflag = 0, p_magic 
> = 3203398350, p_osrel = 1100090, 
> >   p_comm = 0xf800304df3c4 "privoxy",  
> p_pgrp = 0x618b0080,
> 
> > I've changed p's declaration to static so hopefully its value will
> > be available the next time the panic occurs, but it may take a while
> > until that happens.  
> 
> From the state of the process you provided, it is a new (zigote) of the
> forking process, which was already linked into allproc list.  Also,
> it seems that bzero part of the forking procedure was finished, but bcopy
> was not yet.  The p_pgrp cannot be a pointer, it is not yet initialized.
> 
> There, we have at least one issue, since zigote is linked before the
> p_pgrp is initialized, and the proctree/allproc locks are dropped.
> As result, fork_findpid() accesses memory with undefined content.
> 
> It seems that the least morbid solution is to slightly extend the scope
> of the allproc lock in do_fork(), to prevent fork_findpid() from working
> while we did not finished copying data from old to new process.

Thanks. I'm currently testing the patch on three systems but it may take a 
while ...

Fabian


pgpvGkzQ7IxHR.pgp
Description: OpenPGP digital signature

fork_findpid() - Fatal trap 12: page fault while in kernel mode

[Fabian Keil]

I've seen the following panic a couple of times in the last three
months, usually while poudriere was running and with sh being the
current process.

This one is from a system based on r290926 running with
kern.randompid=9001 and forking frequently (>1000 forks/second)
due to poudriere and afl-fuzz:

Fatal trap 12: page fault while in kernel mode
cpuid = 1; apic id = 04
fault virtual address   = 0x618b00a8
fault code  = supervisor read data, page not present
instruction pointer = 0x20:0x80909158
stack pointer   = 0x28:0xfe011e03b940
frame pointer   = 0x28:0xfe011e03b960
code segment= base 0x0, limit 0xf, type 0x1b
= DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags= interrupt enabled, resume, IOPL = 0
current process = 71325 (sh)
trap number = 12
panic: page fault
cpuid = 1
KDB: stack backtrace:
[...]
Uptime: 13d20h43m20s
[...]
(kgdb) where
#0  doadump (textdump=1) at pcpu.h:221
#1  0x8094a923 in kern_reboot (howto=260) at 
/usr/src/sys/kern/kern_shutdown.c:364
#2  0x8094ae8b in vpanic (fmt=, ap=) at /usr/src/sys/kern/kern_shutdown.c:757
#3  0x8094acc3 in panic (fmt=0x0) at 
/usr/src/sys/kern/kern_shutdown.c:688
#4  0x80c2fbb1 in trap_fatal (frame=, eva=) at /usr/src/sys/amd64/amd64/trap.c:834
#5  0x80c2fda4 in trap_pfault (frame=0xfe011e03b890, 
usermode=) at /usr/src/sys/amd64/amd64/trap.c:684
#6  0x80c2f55e in trap (frame=0xfe011e03b890) at 
/usr/src/sys/amd64/amd64/trap.c:435
#7  0x80c120a7 in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:234
#8  0x80909158 in fork_findpid (flags=) at 
/usr/src/sys/kern/kern_fork.c:281
#9  0x80907225 in do_fork (td=0xf8009db9a9a0, flags=20, 
p2=0xf8009dbe1a90, td2=0xf800aa6884d0, vm2=0xf800a9eee000, 
pdflags=0) at /usr/src/sys/kern/kern_fork.c:385
#10 0x80906c08 in fork1 (td=0xf8009db9a9a0, flags=20, pages=, procp=0xfe011e03bac0, procdescp=0x0, pdflags=9, 
fcaps=)
at /usr/src/sys/kern/kern_fork.c:937
#11 0x809066ca in sys_fork (td=0xf8009db9a9a0, uap=) at /usr/src/sys/kern/kern_fork.c:108
#12 0x80c3054b in amd64_syscall (td=0xf8009db9a9a0, traced=0) at 
subr_syscall.c:140
#13 0x80c1238b in Xfast_syscall () at 
/usr/src/sys/amd64/amd64/exception.S:394
#14 0x0008009257aa in ?? ()
Previous frame inner to this frame (corrupt stack?)
Current language:  auto; currently minimal
(kgdb) f 8
#8  0x80909158 in fork_findpid (flags=) at 
/usr/src/sys/kern/kern_fork.c:281
warning: Source file is more recent than executable.
   
281 (p->p_pgrp != NULL &&
(kgdb) l -
271  * id is kept reserved only while there is a
272  * non-reaped process in the subtree, so amount of
273  * reserved pids is limited by process limit times
274  * two.
275  */
276 p = LIST_FIRST();
277 again:
278 for (; p != NULL; p = LIST_NEXT(p, p_list)) {
279 while (p->p_pid == trypid ||
280 p->p_reapsubtree == trypid ||
(kgdb) l
281 (p->p_pgrp != NULL &&
282 (p->p_pgrp->pg_id == trypid ||
283 (p->p_session != NULL &&
284 p->p_session->s_sid == trypid {
285 trypid++;
286 if (trypid >= pidchecked)
287 goto retry;
288 }
289 if (p->p_pid > trypid && pidchecked > p->p_pid)
290 pidchecked = p->p_pid;
(kgdb) f 6
#6  0x80c2f55e in trap (frame=0xfe011e03b890) at 
/usr/src/sys/amd64/amd64/trap.c:435
warning: Source file is more recent than executable.
   
435 (void) trap_pfault(frame, FALSE);
(kgdb) p *frame
$2 = {tf_rdi = 1636499584, tf_rsi = 51281, tf_rdx = -8795282608128, tf_rcx = 1, 
tf_r8 = 9, tf_r9 = 9, tf_rax = 0, tf_rbx = 60137, tf_rbp = 
-2194224727712, tf_r10 = 0, tf_r11 = 0,
  tf_r12 = -8793446540656, tf_r13 = -2194224727360, tf_r14 = 0, tf_r15 = 
-8793450915184, tf_trapno = 12, tf_fs = 19, tf_gs = 27, tf_addr = 1636499624, 
tf_flags = 1, tf_es = 59, tf_ds = 59, tf_err = 0,
  tf_rip = -2138009256, tf_cs = 32, tf_rflags = 66050, tf_rsp = -2194224727728, 
tf_ss = 40}
(kgdb) f 9
#9  0x80907225 in do_fork (td=0xf8009db9a9a0, flags=20, 
p2=0xf8009dbe1a90, td2=0xf800aa6884d0, vm2=0xf800a9eee000, 
pdflags=0) at /usr/src/sys/kern/kern_fork.c:385
385 trypid = fork_findpid(flags);
(kgdb) p flags
$3 = 20
(kgdb) p *td
$4 = {td_lock = 0x8129b100, td_proc = 0xf8009d7b5a90, 

panic: devfs_fsync: vop_stdfsync failed.

[Fabian Keil]

I got the following panic by impatiently unplugging a device while a
msdosfs partition on it was in the process of getting unmounted:

Unread portion of the kernel message buffer:
[368] Device IPOD went missing before all of the data could be written to it; 
expect data loss.
[368] fsync: giving up on dirty
[368] 0xf80011b24760: tag devfs, type VCHR
[368] usecount 1, writecount 0, refcount 4770 mountedhere 0xf800061eb200
[368] flags (VI_DOOMED|VI_ACTIVE)
[368] v_object 0xf80011a4c500 ref 0 pages 4782 cleanbuf 4766 dirtybuf 1
[368] lock type devfs: EXCL by thread 0xf80010c424d0 (pid 40394, sudo, 
tid 101528)
[368]   dev msdosfs/IPOD
[368] panic: devfs_fsync: vop_stdfsync failed.
[...]
(kgdb) where
#0  doadump (textdump=0) at pcpu.h:221
#1  0x80316e5b in db_dump (dummy=, dummy2=false, 
dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:533
#2  0x80316c4e in db_command (cmd_table=0x0) at 
/usr/src/sys/ddb/db_command.c:440
#3  0x803169e4 in db_command_loop () at 
/usr/src/sys/ddb/db_command.c:493
#4  0x803194eb in db_trap (type=, code=0) at 
/usr/src/sys/ddb/db_main.c:251
#5  0x805e2923 in kdb_trap (type=3, code=0, tf=) 
at /usr/src/sys/kern/subr_kdb.c:654
#6  0x8087cb27 in trap (frame=0xfe009464a0b0) at 
/usr/src/sys/amd64/amd64/trap.c:549
#7  0x80861ad7 in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:234
#8  0x805e200b in kdb_enter (why=0x8096fb7b "panic", msg=0x32 
) at cpufunc.h:63
#9  0x8059e5af in vpanic (fmt=, ap=) at /usr/src/sys/kern/kern_shutdown.c:750
#10 0x8059e403 in panic (fmt=0x0) at 
/usr/src/sys/kern/kern_shutdown.c:688
#11 0x80459e1f in devfs_fsync (ap=) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:688
#12 0x80902206 in VOP_FSYNC_APV (vop=, a=) at vnode_if.c:1328
#13 0x8063dba5 in bufsync (bo=, waitfor=) at vnode_if.h:549
#14 0x8065bc3c in bufobj_invalbuf (bo=0xf80011b24830, flags=1, 
slpflag=0, slptimeo=0) at /usr/src/sys/kern/vfs_subr.c:1517
#15 0x8065f23e in vgonel (vp=) at 
/usr/src/sys/kern/vfs_subr.c:1595
#16 0x8065f8e7 in vgone (vp=0xf80011b24760) at 
/usr/src/sys/kern/vfs_subr.c:3006
#17 0x80453152 in devfs_delete (dm=0xf80002428080, 
de=0xf800062d2d00, flags=0) at /usr/src/sys/fs/devfs/devfs_devs.c:390
#18 0x80453663 in devfs_populate_loop (dm=0xf80002428080, 
cleanup=) at /usr/src/sys/fs/devfs/devfs_devs.c:528
#19 0x8045344a in devfs_populate (dm=0xf80002428080) at 
/usr/src/sys/fs/devfs/devfs_devs.c:655
#20 0x8045914e in devfs_populate_vp (vp=0xf80006130588) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:239
#21 0x80456c4c in devfs_lookup (ap=0xfe009464a6d8) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:1042
#22 0x80900e90 in VOP_LOOKUP_APV (vop=, a=) at vnode_if.c:127
#23 0x8065131e in lookup (ndp=0xfe009464a9b0) at vnode_if.h:54
#24 0x806509f1 in namei (ndp=) at 
/usr/src/sys/kern/vfs_lookup.c:306
#25 0x8066ed7c in vn_open_cred (ndp=0xfe009464a9b0, 
flagp=0xfe009464aa8c, cmode=0, vn_open_flags=0, cred=0xf80010467400, 
fp=0xf8000633c780) at /usr/src/sys/kern/vfs_vnops.c:277
#26 0x80667eef in kern_openat (td=0xf80010c424d0, fd=-100, 
path=0x41527f , pathseg=UIO_USERSPACE, 
flags=Cannot access memory at address 0x32
) at /usr/src/sys/kern/vfs_syscalls.c:1005
#27 0x8087db2b in amd64_syscall (td=0xf80010c424d0, traced=0) at 
subr_syscall.c:140
#28 0x80861dbb in Xfast_syscall () at 
/usr/src/sys/amd64/amd64/exception.S:394
#29 0x000800f4d7aa in ?? ()
Previous frame inner to this frame (corrupt stack?)
Current language:  auto; currently minimal
(kgdb) f 11
#11 0x80459e1f in devfs_fsync (ap=) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:688
688 panic("devfs_fsync: vop_stdfsync 
failed.");
(kgdb) l -
678 if (!vn_isdisk(ap->a_vp, )) {
679 bo = >a_vp->v_bufobj;
680 de = ap->a_vp->v_data;
681 if (error == ENXIO && bo->bo_dirty.bv_cnt > 0) {
682 printf("Device %s went missing before all of 
the data "
683 "could be written to it; expect data 
loss.\n",
684 de->de_dirent->d_name);
685 
686 error = vop_stdfsync(ap);
687 if (bo->bo_dirty.bv_cnt != 0 || error != 0)
(kgdb) l
688 panic("devfs_fsync: vop_stdfsync 
failed.");


Shouldn't vop_stdfsync() be expected to fail if the device went missing?

My kernel is based on r291864 but the printf+panic code was added years
ago in r186911 and the commit message suggests that it prevents a different
panic:

commit d72b8ba20f3993d4517a73171cb5e4a269b103a6
Author: trasz 
Date:   Thu Jan 8 19:13:34 2009 +

Don't 

Re: panic: vm_fault: fault on nofault entry, addr: fffffe00873d8000

[Fabian Keil]

Konstantin Belousov <kostik...@gmail.com> wrote:

> On Sun, Dec 06, 2015 at 06:51:36PM +0100, Fabian Keil wrote:
> > > > #16 0x80877d5a in bcopy () at 
> > > > /usr/src/sys/amd64/amd64/support.S:118
> > > > #17 0x805f64e8 in uiomove_faultflag (cp=, 
> > > > n=, uio=0xfe009444aae0, nofault= > > > optimized out>) at /usr/src/sys/kern/subr_uio.c:208
> > > > #18 0x8046236f in msdosfs_read (ap=) at 
> > > > /usr/src/sys/fs/msdosfs/msdosfs_vnops.c:596
> > > > #19 0x808feb20 in VOP_READ_APV (vop=, 
> > > > a=) at vnode_if.c:930
> > > > #20 0x8039bf3a in mdstart_vnode (sc=0xf8004c7ce000, 
> > > > bp=0xf80028fc81f0) at vnode_if.h:384
> > > From the frame 20, do 'p *bp' in kgdb and mail the result.  Do you have
> > > any non-standard values for buffer cache knobs, esp. for MAXPHYS ?  
> > 
> > (kgdb) p *bp
> > $1 = {bio_cmd = 1 '\001', bio_flags = 16 '\020', bio_cflags = 0 '\0', 
> > bio_pflags = 0 '\0', bio_dev = 0x0, bio_disk = 0x0, bio_offset = 0, 
> > bio_bcount = 0, 
> >   bio_data = 0xfe0077d94000 , 
> > bio_ma = 0xf8000275bc00, bio_ma_offset = 960,  
> 
> bio_ma_n = 33,
> This is the issue.  The upper layer (ZFS ?) passed down the request
> which is max-sized (see bio_length == 32 pages) but not aligned.
> The physical buffer used for transient mapping cannot handle this.
> 
> bio_error = 0, bio_resid = 0, 
> >   bio_done = 0x804e51d0 , bio_driver1 = 0x0, 
> > bio_driver2 = 0x0, bio_caller1 = 0x0, bio_caller2 = 0x0, bio_queue = 
> > {tqe_next = 0x0, tqe_prev = 0xf8004c7ce018}, bio_attribute = 0x0, 
> >   bio_from = 0xf80010131d80, bio_to = 0xf800694f2a00, bio_length = 
> > 131072, bio_completed = 0, bio_children = 0, bio_inbed = 0, bio_parent = 
> > 0xf8000628bd90, bio_t0 = {sec = 33029, 
> > frac = 13163670047247984455}, bio_task = 0, bio_task_arg = 0x0, 
> > bio_classifier1 = 0x0, bio_classifier2 = 0x0, bio_pblkno = 0}
> >  
> > I don't use non-standard values for MAXPHYS or other buffer cache settings.
> >   
> 
> Try the following patch.

With this patch I got:

[400] Fatal trap 9: general protection fault while in kernel mode
[400] cpuid = 0; apic id = 00
[400] instruction pointer   = 0x20:0x8086c603
[400] stack pointer = 0x28:0xfe0094422a60
[400] frame pointer = 0x28:0xfe0094422a80
[400] code segment  = base 0x0, limit 0xf, type 0x1b
[400]   = DPL 0, pres 1, long 1, def32 0, gran 1
[400] processor eflags  = interrupt enabled, resume, IOPL = 0
[400] current process   = 34142 (md0)
[...]
(kgdb) where
#0  doadump (textdump=0) at pcpu.h:221
#1  0x80316e5b in db_dump (dummy=, dummy2=false, 
dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:533
#2  0x80316c4e in db_command (cmd_table=0x0) at 
/usr/src/sys/ddb/db_command.c:440
#3  0x803169e4 in db_command_loop () at 
/usr/src/sys/ddb/db_command.c:493
#4  0x803194eb in db_trap (type=, code=0) at 
/usr/src/sys/ddb/db_main.c:251
#5  0x805e2933 in kdb_trap (type=9, code=0, tf=) 
at /usr/src/sys/kern/subr_kdb.c:654
#6  0x8087d161 in trap_fatal (frame=0xfe00944229b0, eva=) at /usr/src/sys/amd64/amd64/trap.c:829
#7  0x8087ce3c in trap (frame=) at 
/usr/src/sys/amd64/amd64/trap.c:203
#8  0x80861ae7 in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:234
#9  0x8086c603 in pmap_qenter (sva=18446741876956168192, ma=, count=32) at /usr/src/sys/amd64/amd64/pmap.c:1991
#10 0x8039e673 in mdstart_vnode (sc=0xf80029ac7800, 
bp=0xf800270c15d0) at /usr/src/sys/dev/md/md.c:928
#11 0x8039c73c in md_kthread (arg=0xf80029ac7800) at 
/usr/src/sys/dev/md/md.c:1158
#12 0x8055c16c in fork_exit (callout=0x8039c510 , 
arg=0xf80029ac7800, frame=0xfe0094422c00) at 
/usr/src/sys/kern/kern_fork.c:1011
#13 0x8086201e in fork_trampoline () at 
/usr/src/sys/amd64/amd64/exception.S:609
#14 0x in ?? ()
Current language:  auto; currently minimal
(kgdb) f 9
#9  0x8086c603 in pmap_qenter (sva=18446741876956168192, ma=, count=32) at /usr/src/sys/amd64/amd64/pmap.c:1991
1991m = *ma++;
(kgdb) f 10
#10 0x8039e673 in mdstart_vnode (sc=0xf80029ac7800, 
bp=0xf800270c15d0) at /usr/src/sys/dev/md/md.c:928
928 pmap_qenter((vm_offset_t)pb->b_data,
(kgdb) l
923 unmapped_step:
924 npages = min(MAXPHYS, roundup2(len + ma_offs, 
PAGE_SIZE)) /
925 PAGE_SIZE;
926 iolen = min(npages * PAGE_SIZE - ma_offs, len);
927 KASSERT(iolen > 0, ("

Re: panic: vm_fault: fault on nofault entry, addr: fffffe00873d8000

[Fabian Keil]

Konstantin Belousov <kostik...@gmail.com> wrote:

> On Sun, Dec 06, 2015 at 11:45:32AM +0100, Fabian Keil wrote:
> > I got the following panic while trying to import a ZFS pool from a
> > geli-encrypted memory disk backed by a file located on a msdosfs partition: 
> >  
> I smiled.

I occasionally use this somewhat non-standard setup to store redundant
backups on a media player whose bootloader may not be prepared to deal
with multiple partitions ...

> > (kgdb) where
> > #0  doadump (textdump=0) at pcpu.h:221
> > #1  0x80314c1b in db_dump (dummy=, 
> > dummy2=false, dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:533
> > #2  0x80314a0e in db_command (cmd_table=0x0) at 
> > /usr/src/sys/ddb/db_command.c:440
> > #3  0x803147a4 in db_command_loop () at 
> > /usr/src/sys/ddb/db_command.c:493
> > #4  0x803172ab in db_trap (type=, code=0) at 
> > /usr/src/sys/ddb/db_main.c:251
> > #5  0x805dfe33 in kdb_trap (type=3, code=0, tf= > out>) at /usr/src/sys/kern/subr_kdb.c:654
> > #6  0x80879bc7 in trap (frame=0xfe009444a240) at 
> > /usr/src/sys/amd64/amd64/trap.c:549
> > #7  0x8085eb77 in calltrap () at 
> > /usr/src/sys/amd64/amd64/exception.S:234
> > #8  0x805df51b in kdb_enter (why=0x8096c7fb "panic", 
> > msg=0x32 ) at cpufunc.h:63
> > #9  0x8059bbdf in vpanic (fmt=, ap= > optimized out>) at /usr/src/sys/kern/kern_shutdown.c:750
> > #10 0x8059ba33 in panic (fmt=0x0) at 
> > /usr/src/sys/kern/kern_shutdown.c:688
> > #11 0x8082ffb5 in vm_fault_hold (map=, 
> > vaddr=, fault_type=, 
> > fault_flags=, m_hold=)
> > at /usr/src/sys/vm/vm_fault.c:332
> > #12 0x8082de18 in vm_fault (map=0xf8000200, vaddr= > optimized out>, fault_type=2 '\002', fault_flags=0) at 
> > /usr/src/sys/vm/vm_fault.c:277
> > #13 0x8087a33a in trap_pfault (frame=0xfe009444a8e0, 
> > usermode=0) at /usr/src/sys/amd64/amd64/trap.c:734
> > #14 0x80879bde in trap (frame=0xfe009444a8e0) at 
> > /usr/src/sys/amd64/amd64/trap.c:435
> > #15 0x8085eb77 in calltrap () at 
> > /usr/src/sys/amd64/amd64/exception.S:234
> > #16 0x80877d5a in bcopy () at /usr/src/sys/amd64/amd64/support.S:118
> > #17 0x805f64e8 in uiomove_faultflag (cp=, 
> > n=, uio=0xfe009444aae0, nofault= > out>) at /usr/src/sys/kern/subr_uio.c:208
> > #18 0x8046236f in msdosfs_read (ap=) at 
> > /usr/src/sys/fs/msdosfs/msdosfs_vnops.c:596
> > #19 0x808feb20 in VOP_READ_APV (vop=, a= > optimized out>) at vnode_if.c:930
> > #20 0x8039bf3a in mdstart_vnode (sc=0xf8004c7ce000, 
> > bp=0xf80028fc81f0) at vnode_if.h:384  
> From the frame 20, do 'p *bp' in kgdb and mail the result.  Do you have
> any non-standard values for buffer cache knobs, esp. for MAXPHYS ?

(kgdb) p *bp
$1 = {bio_cmd = 1 '\001', bio_flags = 16 '\020', bio_cflags = 0 '\0', 
bio_pflags = 0 '\0', bio_dev = 0x0, bio_disk = 0x0, bio_offset = 0, bio_bcount 
= 0, 
  bio_data = 0xfe0077d94000 , 
bio_ma = 0xf8000275bc00, bio_ma_offset = 960, bio_ma_n = 33, bio_error = 0, 
bio_resid = 0, 
  bio_done = 0x804e51d0 , bio_driver1 = 0x0, bio_driver2 = 
0x0, bio_caller1 = 0x0, bio_caller2 = 0x0, bio_queue = {tqe_next = 0x0, 
tqe_prev = 0xf8004c7ce018}, bio_attribute = 0x0, 
  bio_from = 0xf80010131d80, bio_to = 0xf800694f2a00, bio_length = 
131072, bio_completed = 0, bio_children = 0, bio_inbed = 0, bio_parent = 
0xf8000628bd90, bio_t0 = {sec = 33029, 
frac = 13163670047247984455}, bio_task = 0, bio_task_arg = 0x0, 
bio_classifier1 = 0x0, bio_classifier2 = 0x0, bio_pblkno = 0}
 
I don't use non-standard values for MAXPHYS or other buffer cache settings.

Fabian


pgp8Ii1rOogBq.pgp
Description: OpenPGP digital signature

panic: vm_fault: fault on nofault entry, addr: fffffe00873d8000

[Fabian Keil]

I got the following panic while trying to import a ZFS pool from a
geli-encrypted memory disk backed by a file located on a msdosfs partition:

(kgdb) where
#0  doadump (textdump=0) at pcpu.h:221
#1  0x80314c1b in db_dump (dummy=, dummy2=false, 
dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:533
#2  0x80314a0e in db_command (cmd_table=0x0) at 
/usr/src/sys/ddb/db_command.c:440
#3  0x803147a4 in db_command_loop () at 
/usr/src/sys/ddb/db_command.c:493
#4  0x803172ab in db_trap (type=, code=0) at 
/usr/src/sys/ddb/db_main.c:251
#5  0x805dfe33 in kdb_trap (type=3, code=0, tf=) 
at /usr/src/sys/kern/subr_kdb.c:654
#6  0x80879bc7 in trap (frame=0xfe009444a240) at 
/usr/src/sys/amd64/amd64/trap.c:549
#7  0x8085eb77 in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:234
#8  0x805df51b in kdb_enter (why=0x8096c7fb "panic", msg=0x32 
) at cpufunc.h:63
#9  0x8059bbdf in vpanic (fmt=, ap=) at /usr/src/sys/kern/kern_shutdown.c:750
#10 0x8059ba33 in panic (fmt=0x0) at 
/usr/src/sys/kern/kern_shutdown.c:688
#11 0x8082ffb5 in vm_fault_hold (map=, 
vaddr=, fault_type=, 
fault_flags=, m_hold=)
at /usr/src/sys/vm/vm_fault.c:332
#12 0x8082de18 in vm_fault (map=0xf8000200, vaddr=, fault_type=2 '\002', fault_flags=0) at 
/usr/src/sys/vm/vm_fault.c:277
#13 0x8087a33a in trap_pfault (frame=0xfe009444a8e0, usermode=0) at 
/usr/src/sys/amd64/amd64/trap.c:734
#14 0x80879bde in trap (frame=0xfe009444a8e0) at 
/usr/src/sys/amd64/amd64/trap.c:435
#15 0x8085eb77 in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:234
#16 0x80877d5a in bcopy () at /usr/src/sys/amd64/amd64/support.S:118
#17 0x805f64e8 in uiomove_faultflag (cp=, n=, uio=0xfe009444aae0, nofault=) at 
/usr/src/sys/kern/subr_uio.c:208
#18 0x8046236f in msdosfs_read (ap=) at 
/usr/src/sys/fs/msdosfs/msdosfs_vnops.c:596
#19 0x808feb20 in VOP_READ_APV (vop=, a=) at vnode_if.c:930
#20 0x8039bf3a in mdstart_vnode (sc=0xf8004c7ce000, 
bp=0xf80028fc81f0) at vnode_if.h:384
#21 0x8039a3cc in md_kthread (arg=0xf8004c7ce000) at 
/usr/src/sys/dev/md/md.c:979
#22 0x8055978c in fork_exit (callout=0x8039a1a0 , 
arg=0xf8004c7ce000, frame=0xfe009444ac00) at 
/usr/src/sys/kern/kern_fork.c:1011
#23 0x8085f0ae in fork_trampoline () at 
/usr/src/sys/amd64/amd64/exception.S:609
#24 0x in ?? ()
Current language:  auto; currently minimal

This is the second time I've seen this, the first time was with a kernel
based on r290573 in November, but as I wasn't able to intentionally reproduce
it with a more recent kernel my assumption was that the problem had already
been fixed.

Currently my kernel is based on r291706.

Any ideas?

Fabian


pgpQI7N3Yo7h5.pgp
Description: OpenPGP digital signature

Re: ZFS-related panic: "possible" spa->spa_errlog_lock deadlock

[Fabian Keil]

Fabian Keil <freebsd-lis...@fabiankeil.de> wrote:

> Xin Li <delp...@delphij.net> wrote:
> 
> > On 9/7/14 11:23 PM, Fabian Keil wrote:  
> > > Xin Li <delp...@delphij.net> wrote:
> > > 
> > >> On 9/7/14 9:02 PM, Fabian Keil wrote:
> > >>> Using a kernel built from FreeBSD 11.0-CURRENT r271182 I got
> > >>> the following panic yesterday:
> > >>> 
> > >>> [...] Unread portion of the kernel message buffer: [6880]
> > >>> panic: deadlkres: possible deadlock detected for
> > >>> 0xf80015289490, blocked for 1800503 ticks
> > >> 
> > >> Any chance to get all backtraces (e.g. thread apply all bt full
> > >> 16)? I think a different thread that held the lock have been
> > >> blocked, probably related to your disconnected vdev.
> > > 
> > > Output of "thread apply all bt full 16" is available at: 
> > > http://www.fabiankeil.de/tmp/freebsd/kgdb-output-spa_errlog_lock-deadlock.txt
> > >
> > >  A lot of the backtraces prematurely end with "Cannot access memory
> > > at address", therefore I also added "thread apply all bt" output.
> > > 
> > > Apparently there are at least two additional threads blocking below
> > > spa_get_stats():  
> [...]
> > Yes, thread 1182 owned the lock and is waiting for the zio be done.
> > Other threads that wanted the lock would have to wait.
> > 
> > I don't have much clue why the system entered this state, however, as
> > the operations should have errored out (the GELI device is gone on
> > 21:44:56 based on your log, which suggests all references were closed)
> > instead of waiting.  

> I finally found the time to analyse the problem which seems
> to be that spa_sync() requires at least one writeable vdev to
> complete, but holds the lock(s) required to remove or bring back
> vdevs.
> 
> Letting spa_sync() drop the lock and wait for at least one vdev
> to become writeable again seems to make the problem unreproducible
> for me, but probably merely shrinks the race window and thus is not
> a complete solution.
> 
> For details see:
> https://www.fabiankeil.de/sourcecode/electrobsd/ZFS-Optionally-let-spa_sync-wait-for-writable-vdev.diff

Patch updated to unbreak the userspace build and to note that the
deadlock can still be reproduced with an artifical test case like:

Shell 1:
  mdconfig -u 0 -f /dpool/scratch/test-vdev.img
  zpool create test /dev/md0
  while sleep 1; do
mdconfig -d -u 0 -o force &&
mdconfig -f /dpool/scratch/test-vdev.img &&
zpool clear test;
  done
Shell 2:
  # Cause writes to the pool from another shell, for example
  # by creating datasets.

Log excerpt (from test begin to deadlock):
Oct 29 12:34:28 kendra ZFS: vdev state changed, pool_guid=16039353738236808887 
vdev_guid=3080051161477470469
[...]
Oct 29 12:46:57 kendra ZFS: vdev state changed, pool_guid=16039353738236808887 
vdev_guid=3080051161477470469
Oct 29 12:46:59 kendra ZFS: vdev is removed, pool_guid=16039353738236808887 
vdev_guid=3080051161477470469
Oct 29 12:46:59 kendra ZFS: vdev state changed, pool_guid=16039353738236808887 
vdev_guid=3080051161477470469
Oct 29 12:47:00 kendra kernel: g_dev_taste: make_dev_p() failed (gp->name=md0, 
error=17)

With the deadman enabled, this will also cause:
 panic: I/O to pool 'test' appears to be hung on vdev guid 3080051161477470469 
at '/dev/md0'.
 cpuid = 0
 KDB: stack backtrace:
 db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfe01136af870
 vpanic() at vpanic+0x182/frame 0xfe01136af8f0
 panic() at panic+0x43/frame 0xfe01136af950
 vdev_deadman() at vdev_deadman+0x127/frame 0xfe01136af9a0
 vdev_deadman() at vdev_deadman+0x40/frame 0xfe01136af9f0
 spa_deadman() at spa_deadman+0x86/frame 0xfe01136afa20
 softclock_call_cc() at softclock_call_cc+0x1a3/frame 0xfe01136afaf0
 softclock() at softclock+0x94/frame 0xfe01136afb20
 intr_event_execute_handlers() at intr_event_execute_handlers+0x1b6/frame 
0xfe01136afb60
 ithread_loop() at ithread_loop+0xa6/frame 0xfe01136afbb0
 fork_exit() at fork_exit+0x9c/frame 0xfe01136afbf0
 fork_trampoline() at fork_trampoline+0xe/frame 0xfe01136afbf0

With test's txg_sync_thread being the offender:
 (kgdb) tid 101874
 [Switching to thread 819 (Thread 101874)]#0  sched_switch 
(td=0xf800513649a0, newtd=, flags=) at /usr/src/sys/kern/sched_ule.c:1969
 1969cpuid = PCPU_GET(cpuid);
 (kgdb) where
 #0  sched_switch (td=0xf800513649a0, newtd=, 
flags=) at /usr/src/sys/kern/sched_ule.c:1969
 #1  0x805a3a18 in mi_switch (flags=260, newtd=0x0) at 
/usr/src/sys/kern/kern_synch.c:470
 #2  0x805ea15a

Re: ZFS-related panic: "possible" spa->spa_errlog_lock deadlock

[Fabian Keil]

Xin Li <delp...@delphij.net> wrote:

> On 9/7/14 11:23 PM, Fabian Keil wrote:
> > Xin Li <delp...@delphij.net> wrote:
> >   
> >> On 9/7/14 9:02 PM, Fabian Keil wrote:  
> >>> Using a kernel built from FreeBSD 11.0-CURRENT r271182 I got
> >>> the following panic yesterday:
> >>> 
> >>> [...] Unread portion of the kernel message buffer: [6880]
> >>> panic: deadlkres: possible deadlock detected for
> >>> 0xf80015289490, blocked for 1800503 ticks  
> >> 
> >> Any chance to get all backtraces (e.g. thread apply all bt full
> >> 16)? I think a different thread that held the lock have been
> >> blocked, probably related to your disconnected vdev.  
> > 
> > Output of "thread apply all bt full 16" is available at: 
> > http://www.fabiankeil.de/tmp/freebsd/kgdb-output-spa_errlog_lock-deadlock.txt
> >
> >  A lot of the backtraces prematurely end with "Cannot access memory
> > at address", therefore I also added "thread apply all bt" output.
> > 
> > Apparently there are at least two additional threads blocking below
> > spa_get_stats():
[...]
> Yes, thread 1182 owned the lock and is waiting for the zio be done.
> Other threads that wanted the lock would have to wait.
> 
> I don't have much clue why the system entered this state, however, as
> the operations should have errored out (the GELI device is gone on
> 21:44:56 based on your log, which suggests all references were closed)
> instead of waiting.

Thanks for the responses.

I finally found the time to analyse the problem which seems
to be that spa_sync() requires at least one writeable vdev to
complete, but holds the lock(s) required to remove or bring back
vdevs.

Letting spa_sync() drop the lock and wait for at least one vdev
to become writeable again seems to make the problem unreproducible
for me, but probably merely shrinks the race window and thus is not
a complete solution.

For details see:
https://www.fabiankeil.de/sourcecode/electrobsd/ZFS-Optionally-let-spa_sync-wait-for-writable-vdev.diff
(Experimental, only lightly tested)

Fabian


pgpeu5mIyy5n5.pgp
Description: OpenPGP digital signature

Re: panic: getblk: size(131072) > MAXBCACHEBUF(65536)

[Fabian Keil]

Mark Johnston <ma...@freebsd.org> wrote:

> On Thu, Oct 01, 2015 at 03:23:56PM +0200, Fabian Keil wrote:
> > Shortly after upgrading to a kernel based on r288437 I got the following
> > panic:
> > 
> > Unread portion of the kernel message buffer:
> > [5112] panic: getblk: size(131072) > MAXBCACHEBUF(65536)
> > [...]

> Thanks for the report. This should be fixed as of r288451. (Sorry for
> misspelling your first name in the commit message!)

No problem. Thanks for the quick fix.

Fabian


pgpF8znVSGYfp.pgp
Description: OpenPGP digital signature

panic: getblk: size(131072) > MAXBCACHEBUF(65536)

[Fabian Keil]

Shortly after upgrading to a kernel based on r288437 I got the following
panic:

Unread portion of the kernel message buffer:
[5112] panic: getblk: size(131072) > MAXBCACHEBUF(65536)
[...]
(kgdb) where
#0  doadump (textdump=0) at pcpu.h:221
#1  0x8030ca9e in db_dump (dummy=, dummy2=false, 
dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:533
#2  0x8030c651 in db_command (cmd_table=0x0) at 
/usr/src/sys/ddb/db_command.c:440
#3  0x8030c2e4 in db_command_loop () at 
/usr/src/sys/ddb/db_command.c:493
#4  0x8030ef0b in db_trap (type=, code=0) at 
/usr/src/sys/ddb/db_main.c:251
#5  0x805d3cd4 in kdb_trap (type=3, code=0, tf=) 
at /usr/src/sys/kern/subr_kdb.c:654
#6  0x808651bf in trap (frame=0xfe009452b5f0) at 
/usr/src/sys/amd64/amd64/trap.c:549
#7  0x80849e4a in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:234
#8  0x805d33ae in kdb_enter (why=0x80953dc1 "panic", 
msg=0x805d9e90 "U[...]") at cpufunc.h:63
#9  0x805902b9 in vpanic (fmt=, ap=) at /usr/src/sys/kern/kern_shutdown.c:746
#10 0x80590103 in panic (fmt=0x0) at 
/usr/src/sys/kern/kern_shutdown.c:684
#11 0x806310e7 in getblk (vp=, blkno=, size=, slpflag=, 
slptimeo=, flags=)
at /usr/src/sys/kern/vfs_bio.c:3324
#12 0x8063cf81 in vop_stdadvise (ap=) at 
/usr/src/sys/kern/vfs_default.c:1099
#13 0x808ec827 in VOP_ADVISE_APV (vop=, a=) at vnode_if.c:3848
#14 0x80662844 in vn_read (fp=, uio=, active_cred=, flags=, 
td=0x8) at vnode_if.h:1648
#15 0x8065e27a in vn_io_fault (fp=0xf8000631eaf0, 
uio=0xfe009452baa0, active_cred=0xfe009452b5a0, flags=0, td=0x8) at 
/usr/src/sys/kern/vfs_vnops.c:1169
#16 0x805f0385 in dofileread (td=0xf800279fd9a0, fd=3, 
fp=0xf8000631eaf0, auio=0xfe009452baa0, offset=, 
flags=50) at file.h:300
#17 0x805f00a8 in kern_readv (td=0xf800279fd9a0, fd=3, 
auio=0xfe009452baa0) at /usr/src/sys/kern/sys_generic.c:273
#18 0x805f0033 in sys_read (td=0x0, uap=) at 
/usr/src/sys/kern/sys_generic.c:186
#19 0x808661e8 in amd64_syscall (td=0xf800279fd9a0, traced=0) at 
subr_syscall.c:139
#20 0x8084a12b in Xfast_syscall () at 
/usr/src/sys/amd64/amd64/exception.S:394
#21 0x0008014d752a in ?? ()
Previous frame inner to this frame (corrupt stack?)
Current language:  auto; currently minimal

The system was running for about 50 minutes before the panic occurred and
didn't do anything special at the time (running Xorg, Firefox, ssh ...).

I suspect r288431 and am currently compiling a kernel with the
commit reverted. The previous kernel was based on r288265.

Fabian


pgpk4obFUFQeP.pgp
Description: OpenPGP digital signature

Re: FreeBSD_HEAD_amd64_gcc4.9 - Build #388 - Still Failing

[Fabian Keil]

Warner Losh i...@bsdimp.com wrote:

 On Fri, Aug 28, 2015 at 4:18 AM, jenkins-ad...@freebsd.org wrote:
 
  gcc4.9/obj/builds/FreeBSD_HEAD_amd64_gcc4.9/sys/boot/i386/gptboot/../../libstand32/libstand.a(qdivrem.o)'
  is incompatible with i386 output
 
 
 This might be due to my bsd.stand.mk stuff. However, since gcc 4.9 is
 non-standard and not officially supported, and since I can't recreate this
 on my system with the stock compiler, it is going to be a while
 until I can find the time to fix it.

I'm using clang from base and got the same failure on amd64.
My workaround was reverting r287227/d1be0bf24ec for now.

Fabian


pgpYoEWPCWgEl.pgp
Description: OpenPGP digital signature

Re: mount(1) at boot hangs in spa_namespace_lock

[Fabian Keil]

Andriy Gapon a...@freebsd.org wrote:

 On 20/08/2015 00:07, Jens Schweikhardt wrote:
  Gang,
  
  for a few weeks now I can't get a CURRENT system to boot. I am using the
  zfsloader and have root fs on ZFS. This has worked flawlessly for more
  than a year.
  
  The last message printed is Mounting local file systems: (from
  rc.d/mountcritlocal) and the system hangs until I push reset. Ctrl-C etc
  are ignored. However, CTRL-T says that mount is running in
  spa_namespace_lock, and the runtime increases at 1 second per second
  which looks like it is busy spinning on that lock.
 
 If you can reproduce the problem reliably could you please test a patch
 from this review request https://reviews.freebsd.org/D3281 ?
 (https://reviews.freebsd.org/D3281?download=true)
 
 If I get a success report then I'll immediately commit the fix.

If it doesn't help, you could also try the patch from:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=198563

Fabian


pgpbrAV0kK1I4.pgp
Description: OpenPGP digital signature

geli AES-XTS provider attachment broken after r285336 (was: svn commit: r285336 - in head/sys: netipsec opencrypto)

[Fabian Keil]

Matthew D. Fuller fulle...@over-yonder.net wrote:

 On Thu, Jul 09, 2015 at 06:16:36PM + I heard the voice of
 George V. Neville-Neil, and lo! it spake thus:
  New Revision: 285336
  URL: https://svnweb.freebsd.org/changeset/base/285336
  
  Log:
Add support for AES modes to IPSec.  These modes work both in software 
  only
mode and with hardware support on systems that have AESNI instructions.
 
 With (apparently) this change, I can trigger a panic at will by
 running
 
 % geli onetime -e AES-XTS -d /dev/ada0s1

Thanks for the heads-up.

As it wasn't obvious to me: the commit broke attachment
of AES-XTS providers in general.

Reverting it lets my test system boot again.

Fabian


pgpqvNlffMPRK.pgp
Description: OpenPGP digital signature

Re: how do I downgrade from 11-current to 10-stable

[Fabian Keil]

Erich Dollansky erichsfreebsdl...@alogt.com wrote:

 On Sat, 30 May 2015 05:52:56 -0400
 Aryeh Friedman aryeh.fried...@gmail.com wrote:
 
  My desktop machine is 11-current and I want to down grade it to
  10-stable how do I do this without needing a reinstall?
  
 
 I did this several times from sources. Be aware of one problem which
 could be fatal. If you created a encrypted partition with GELI and you
 downgrade, the older version might not be able to handle the encryption
 of the newer version. This is not mentioned in the documentation.

The [h]ighest GELI metadata version supported by the given
FreeBSD version is documented in geli(8)'s history section.

Fabian


pgpLEXdQmi9RB.pgp
Description: OpenPGP digital signature

Re: async pass(4) patches available

[Fabian Keil]

Kenneth D. Merry k...@freebsd.org wrote:

 On Mon, Apr 06, 2015 at 15:39:56 +0200, Fabian Keil wrote:
  Kenneth D. Merry k...@freebsd.org wrote:
  
   I have put patches to add an asynchronous interface to the pass(4)
   driver and add a new camdd(8) utility here:
   
   FreeBSD/head as of SVN revision 280857:
   
   http://people.freebsd.org/~ken/async_pass.head.20150330.1.txt
  [...]
   Comments and testing are welcome!  As I said, camdd(8) in particular
   is a work in progress.  It could use some cleanup and there are some
   more useful features that could be added there.
  
  I've been using the patch for a couple of days on an amd64 system
  based on 11.0-CURRENT r280952 and didn't notice any obvious
  regressions using the system as usual.
[...] 
  I also tried to test camdd, but didn't get it to work.
  Some failed attempts:
  
  [fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536 -o file=blafsel.img
  (pass2:umass-sim0:0:0:0): READ(6). CDB: 08 00 00 00 80 00 
  (pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an
  error 13 bytes read from pass2
  13 bytes written to blafsel.img
  20.3203 seconds elapsed
  0.00 MB/sec
  [fk@kendra ~]$ sudo hd blafsel.img 
    55 53 42 53 d9 02 00 00  00 00 01 00 01
  |USBS.| 000d
  [fk@kendra ~]$ sudo dd if=/dev/da0 bs=1k count=1  | hd | head -n 1
  1+0 records in
  1+0 records out
  1024 bytes transferred in 0.000603 secs (1697756 bytes/sec)
    fc 31 c0 8e c0 8e d8 8e  d0 bc 00 0e be 1a 7c bf
  |.1|.|
 
 One possibility is that the device doesn't support 6-byte read/write
 requests.  The da(4) driver has quirk entries and code to figure that out
 and default to 10-byte read/write requests, but camdd(8) doesn't have
 anything like that yet.
 
 I've attached patches to camdd that allow you to specify a minimum
 command size.  So, apply the patches, rebuild camdd, and try this:
 
 # sudo camdd -i pass=da0,bs=65536,mcs=10 -o file=blafsel.img
 
 We'll see if that helps.  I'm not sure why you were even able to get 13
 bytes back.  That is very strange.

With the patch, reading from da0 seems to work until the end,
but again only 13 bytes are written out when writing to a file:

[fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536,mcs=10 -o file=blafsel.img
(pass2:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 78 a8 00 00 00 00 00
(pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an error
4048551936 bytes read from pass2
13 bytes written to blafsel.img
127.6488 seconds elapsed
0.00 MB/sec
[fk@kendra ~]$ diskinfo -v /dev/da0
/dev/da0
512 # sectorsize
4048551936  # mediasize in bytes (3.8G)
7907328 # mediasize in sectors
0   # stripesize
0   # stripeoffset
492 # Cylinders according to firmware.
255 # Heads according to firmware.
63  # Sectors according to firmware.
AA000958# Disk ident.

It works as expected when writing to stdout, though, so this is
probably just a camdd-internal issue:

[fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536,mcs=10 -o file=-  
/dpool/scratch/blafasel.img
(pass2:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 78 a8 00 00 00 00 00
(pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an error
4048551936 bytes read from pass2
4048551936 bytes written to -
128.7222 seconds elapsed
29.99 MB/sec

[fk@kendra ~]$ sudo dd if=/dev/da0 bs=65536 of=/dpool/scratch/blafasel-dd.img
61776+0 records in
61776+0 records out
4048551936 bytes transferred in 134.993030 secs (29990822 bytes/sec)

[fk@kendra ~]$ sha1 /dpool/scratch/blafasel*.img
SHA1 (/dpool/scratch/blafasel-dd.img) = 12d1d9e82f840a6c6485ffcdb1fbf780266ed266
SHA1 (/dpool/scratch/blafasel.img) = 12d1d9e82f840a6c6485ffcdb1fbf780266ed266

Looks good to me.

Fabian


pgpgjgDl4f968.pgp
Description: OpenPGP digital signature

Re: async pass(4) patches available

[Fabian Keil]

Kenneth D. Merry k...@freebsd.org wrote:

 On Tue, Apr 07, 2015 at 13:16:04 +0200, Fabian Keil wrote:
  Kenneth D. Merry k...@freebsd.org wrote:
  
   On Mon, Apr 06, 2015 at 15:39:56 +0200, Fabian Keil wrote:
Kenneth D. Merry k...@freebsd.org wrote:

 I have put patches to add an asynchronous interface to the
 pass(4) driver and add a new camdd(8) utility here:
 
 FreeBSD/head as of SVN revision 280857:
 
 http://people.freebsd.org/~ken/async_pass.head.20150330.1.txt
[...]
 Comments and testing are welcome!  As I said, camdd(8) in
 particular is a work in progress.  It could use some cleanup and
 there are some more useful features that could be added there.

I've been using the patch for a couple of days on an amd64 system
based on 11.0-CURRENT r280952 and didn't notice any obvious
regressions using the system as usual.
  [...] 
I also tried to test camdd, but didn't get it to work.
Some failed attempts:

[fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536 -o file=blafsel.img
(pass2:umass-sim0:0:0:0): READ(6). CDB: 08 00 00 00 80 00 
(pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an
error 13 bytes read from pass2
13 bytes written to blafsel.img
20.3203 seconds elapsed
0.00 MB/sec
[fk@kendra ~]$ sudo hd blafsel.img 
  55 53 42 53 d9 02 00 00  00 00 01 00 01
|USBS.| 000d
[fk@kendra ~]$ sudo dd if=/dev/da0 bs=1k count=1  | hd | head -n 1
1+0 records in
1+0 records out
1024 bytes transferred in 0.000603 secs (1697756 bytes/sec)
  fc 31 c0 8e c0 8e d8 8e  d0 bc 00 0e be 1a 7c bf
|.1|.|
   
   One possibility is that the device doesn't support 6-byte read/write
   requests.  The da(4) driver has quirk entries and code to figure
   that out and default to 10-byte read/write requests, but camdd(8)
   doesn't have anything like that yet.
   
   I've attached patches to camdd that allow you to specify a minimum
   command size.  So, apply the patches, rebuild camdd, and try this:
   
   # sudo camdd -i pass=da0,bs=65536,mcs=10 -o file=blafsel.img
   
   We'll see if that helps.  I'm not sure why you were even able to get
   13 bytes back.  That is very strange.
  
  With the patch, reading from da0 seems to work until the end,
  but again only 13 bytes are written out when writing to a file:
  
  [fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536,mcs=10 -o
  file=blafsel.img (pass2:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 78
  a8 00 00 00 00 00 (pass2:umass-sim0:0:0:0): CAM status: CCB request
  completed with an error 4048551936 bytes read from pass2
  13 bytes written to blafsel.img
  127.6488 seconds elapsed
  0.00 MB/sec
 
 Did the file exist before running that command?  If so, camdd will look
 at the file size and not write any more than the current file size.

That was probably it, at least I couldn't reproduce the problem
with a new file a few minutes ago:

[fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536,mcs=10 -o 
file=/dpool/scratch/new-file.img  
(pass2:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 78 a8 00 00 00 00 00 
(pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an error
4048551936 bytes read from pass2
4048551936 bytes written to /dpool/scratch/new-file.img
127.3009 seconds elapsed
30.33 MB/sec

and with an existing file camdd indeed behaved like you described:

[fk@kendra ~]$ truncate -s 100 /dpool/scratch/small-file
[fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536,mcs=10 -o 
file=/dpool/scratch/small-file  
(pass2:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 78 a8 00 00 00 00 00 
(pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an error
4048551936 bytes read from pass2
100 bytes written to /dpool/scratch/small-file
128.4956 seconds elapsed
0.00 MB/sec

 Thank you for testing it!

No problem.

Fabian


pgpH4scE603mK.pgp
Description: OpenPGP digital signature

Re: async pass(4) patches available

[Fabian Keil]

Kenneth D. Merry k...@freebsd.org wrote:

 I have put patches to add an asynchronous interface to the pass(4) driver
 and add a new camdd(8) utility here:
 
 FreeBSD/head as of SVN revision 280857:
 
 http://people.freebsd.org/~ken/async_pass.head.20150330.1.txt
[...]
 Comments and testing are welcome!  As I said, camdd(8) in particular is a
 work in progress.  It could use some cleanup and there are some more
 useful features that could be added there.

I've been using the patch for a couple of days on an amd64 system
based on 11.0-CURRENT r280952 and didn't notice any obvious
regressions using the system as usual.

Scrubbing a pool once revealed checksum errors which I haven't
seen before:

[fk@kendra ~]$ zpool status -v dpool
  pool: dpool
 state: ONLINE
status: One or more devices has experienced an unrecoverable error.  An
attempt was made to correct the error.  Applications are unaffected.
action: Determine if the device needs to be replaced, and clear the errors
using 'zpool clear' or replace the device with 'zpool replace'.
   see: http://illumos.org/msg/ZFS-8000-9P
  scan: scrub repaired 0 in 1h52m with 0 errors on Thu Apr  2 13:01:44 2015
config:

NAME  STATE READ WRITE CKSUM
dpool ONLINE   0 0 0
  gpt/dpool-ada0.eli  ONLINE   0 0 6

errors: No known data errors

Apr  2 12:31:34 kendra kernel: (ada0:ahcich0:0:0:0): READ_FPDMA_QUEUED. ACB: 60 
30 17 61 55 40 31 00 00 00 00 00
Apr  2 12:31:34 kendra kernel: (ada0:ahcich0:0:0:0): CAM status: ATA Status 
Error
Apr  2 12:31:34 kendra kernel: (ada0:ahcich0:0:0:0): ATA status: 51 (DRDY SERV 
ERR), error: 40 (UNC )
Apr  2 12:31:34 kendra kernel: (ada0:ahcich0:0:0:0): RES: 51 40 3e 61 55 40 31 
00 00 00 00
Apr  2 12:31:34 kendra kernel: (ada0:ahcich0:0:0:0): Error 5, Retries exhausted
Apr  2 12:31:34 kendra kernel: GEOM_ELI: g_eli_read_done() failed 
gpt/dpool-ada0.eli[READ(offset=414970949120, length=24576)]

However the issue doesn't seem to be (easily) reproducible
and could be unrelated.

I also tried to test camdd, but didn't get it to work.
Some failed attempts:

[fk@kendra ~]$ sudo camdd -i pass=da0,bs=65536 -o file=blafsel.img
(pass2:umass-sim0:0:0:0): READ(6). CDB: 08 00 00 00 80 00 
(pass2:umass-sim0:0:0:0): CAM status: CCB request completed with an error
13 bytes read from pass2
13 bytes written to blafsel.img
20.3203 seconds elapsed
0.00 MB/sec
[fk@kendra ~]$ sudo hd blafsel.img 
  55 53 42 53 d9 02 00 00  00 00 01 00 01   |USBS.|
000d
[fk@kendra ~]$ sudo dd if=/dev/da0 bs=1k count=1  | hd | head -n 1
1+0 records in
1+0 records out
1024 bytes transferred in 0.000603 secs (1697756 bytes/sec)
  fc 31 c0 8e c0 8e d8 8e  d0 bc 00 0e be 1a 7c bf  |.1|.|

Trying the block size suggested in the manual result in:

[fk@kendra ~]$ sudo camdd -i pass=da0,bs=1M -o file=blafsel.img
camdd: camdd_pass_run: error sending CAMIOQUEUE ioctl to pass2: Invalid argument
camdd: camdd_pass_run: CCB address is 0x80250e420: Invalid argument
0 bytes read from pass2
0 bytes written to blafsel.img
0.0007 seconds elapsed
0.00 MB/sec

Apr  5 19:08:20 kendra kernel: (pass2:umass-sim0:0:0:0): passmemsetup: data 
length 1048576  max allowed 65536 bytes

Fabian


pgpzmTviVSYQN.pgp
Description: OpenPGP digital signature

Re: URGENT: RNG broken for last 4 months

[Fabian Keil]

John-Mark Gurney j...@funkthat.com wrote:

 Oliver Pinter wrote this message on Tue, Feb 17, 2015 at 23:27 +0100:
  On Tue, Feb 17, 2015 at 11:19 PM, Fabian Keil
  freebsd-lis...@fabiankeil.de wrote:
   John-Mark Gurney j...@funkthat.com wrote:
  
   If you are running a current kernel r273872 or later, please upgrade
   your kernel to r278907 or later immediately and regenerate keys.
  
   I tried ...
  
   start_init: trying /sbin/init
   118[20] Setting hostuuid: [...]
   118[20] Setting hostid: [...
   [20]
   [20]
   [20] Fatal trap 12: page fault while in kernel mode
[...]
 So, this should now be fixed w/:
 Committed revision 278927.

Works for me. Thanks.

Fabian


pgp_5WOGke3Xn.pgp
Description: OpenPGP digital signature

Re: URGENT: RNG broken for last 4 months

[Fabian Keil]

John-Mark Gurney j...@funkthat.com wrote:

 If you are running a current kernel r273872 or later, please upgrade
 your kernel to r278907 or later immediately and regenerate keys.

I tried ...

start_init: trying /sbin/init
118[20] Setting hostuuid: [...]
118[20] Setting hostid: [...
[20] 
[20] 
[20] Fatal trap 12: page fault while in kernel mode
[20] cpuid = 1; apic id = 01
[20] fault virtual address  = 0xf7ff1defb51c
[20] fault code = supervisor read data, page not present
[20] instruction pointer= 0x20:0x819eaed5
[20] stack pointer  = 0x28:0xfe009397b890
[20] frame pointer  = 0x28:0xfe009397b8d0
[20] code segment   = base 0x0, limit 0xf, type 0x1b
[20]= DPL 0, pres 1, long 1, def32 0, gran 1
[20] processor eflags   = interrupt enabled, resume, IOPL = 0
[20] current process= 43 (zfs)
[...]
) at pcpu.h:219
219 pcpu.h: No such file or directory.
in pcpu.h
(kgdb) where
#0  doadump (textdump=Unhandled dwarf expression opcode 0x93
) at pcpu.h:219
#1  0x8031539e in db_dump (dummy=value optimized out, 
dummy2=Unhandled dwarf expression opcode 0x93
) at /usr/src/sys/ddb/db_command.c:533
#2  0x80314e7c in db_command (cmd_table=0x0) at 
/usr/src/sys/ddb/db_command.c:440
#3  0x80314be4 in db_command_loop () at 
/usr/src/sys/ddb/db_command.c:493
#4  0x803177a0 in db_trap (type=value optimized out, code=Unhandled 
dwarf expression opcode 0x93
) at /usr/src/sys/ddb/db_main.c:251
#5  0x805ff8ee in kdb_trap (type=Unhandled dwarf expression opcode 0x93
) at /usr/src/sys/kern/subr_kdb.c:654
#6  0x80889db9 in trap_fatal (frame=0xfe009397b7e0, eva=value 
optimized out) at /usr/src/sys/amd64/amd64/trap.c:856
#7  0x8088a131 in trap_pfault (frame=0xfe009397b7e0, 
usermode=value optimized out) at /usr/src/sys/amd64/amd64/trap.c:678
#8  0x8088976e in trap (frame=0xfe009397b7e0) at 
/usr/src/sys/amd64/amd64/trap.c:426
#9  0x8086cd82 in calltrap () at 
/usr/src/sys/amd64/amd64/exception.S:235
#10 0x819eaed5 in vdev_mirror_dva_select (zio=0xf80006549398, 
p=-974039959) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_mirror.c:317
#11 0x819eae4a in vdev_mirror_preferred_child_randomize 
(zio=0xf80006549398) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_mirror.c:334
#12 0x819eaba1 in vdev_mirror_child_select (zio=0xf80006549398) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_mirror.c:404
#13 0x819ea177 in vdev_mirror_io_start (zio=0xf80006549398) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/vdev_mirror.c:460
#14 0x81a1d73d in zio_vdev_io_start (zio=0xf80006549398) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zio.c:2680
#15 0x81a19c14 in zio_execute (zio=0xf80006549398) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zio.c:1499
#16 0x81a18945 in zio_wait (zio=0xf80006549398) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zio.c:1523
#17 0x81938db2 in arc_read (pio=0x0, spa=0xf8000634e000, 
bp=0xf800065c5048, done=0x81937ae0 arc_getbuf_func, 
private=0xf800065c9410, priority=ZIO_PRIORITY_SYNC_READ, 
zio_flags=128, arc_flags=0xfe009397c004, zb=0xfe009397bfe0) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/arc.c:3610
#18 0x81964326 in dmu_objset_open_impl (spa=0xf8000634e000, ds=0x0, 
bp=0xf800065c5048, osp=0xf800065c5008) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:307
#19 0x81991404 in dsl_pool_init (spa=0xf8000634e000, 
txg=1056266109, dpp=0xf8000634e2e8) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dsl_pool.c:282
#20 0x819c8b08 in spa_load_impl (spa=0xf8000634e000, 
pool_guid=4830954193867998892, config=0xf80002599ee0, state=SPA_LOAD_OPEN, 
type=SPA_IMPORT_EXISTING, mosconfig=0, 
ereport=0xfe009397c4e0) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:2406
#21 0x819c0987 in spa_load (spa=0xf8000634e000, 
state=SPA_LOAD_OPEN, type=SPA_IMPORT_EXISTING, mosconfig=0) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:2178
#22 0x819bfda9 in spa_load_best (spa=0xf8000634e000, 
state=SPA_LOAD_OPEN, mosconfig=0, max_request=18446744073709551615, 
rewind_flags=1)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:2903
#23 0x819babe9 in spa_open_common (pool=0xfe0003232000 tank, 
spapp=0xfe009397c6f0, tag=0x81ade789, nvpolicy=0x0, config=0x0)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:3026
#24 0x819bafcb in spa_open (name=0xfe0003232000 tank, 
spapp=0xfe009397c6f0, tag=0x81ade789) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:3111

Re: Devops question: unattended installs of FreeBSD?

[Fabian Keil]

Jamie Landeg-Jones ja...@dyslexicfish.net wrote:

 Craig Rodrigues rodr...@freebsd.org wrote:
 
  I had a devops person who is familiar with setting up hundreds of
  Linux nodes in cloud environment ask me what is the best way
  to do unattended installs in a cloud environment.
  Linux has kickstart installs, which are quite useful and popular.
 
  What is the equivalent in FreeBSD?
 
 vultr.com has an option to automatically install a freebsd instance
 (it's an automated install, not simply a binary image etc.)
 
 You can even vnc to the console and watch it progress.
 
 Though I'm not sure if the free trial requires credit card authoration -

They do. Vultr is also picky about which credit cards are accepted
(mine weren't, no additional explanation given).

Fabian


pgpRWG4Jkfelg.pgp
Description: OpenPGP digital signature

Re: Panic after USB deadlock followed by kldunload umass.ko

[Fabian Keil]

Fabian Keil freebsd-lis...@fabiankeil.de wrote:

 Hans Petter Selasky h...@selasky.org wrote:
 
  On 10/23/14 16:28, Fabian Keil wrote:
 
   kldunload umass.ko lead to a panic, dumping didn't work.
  
   Screenshots are available at:
   http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r273434-usb/
  
   I've seen locked-up usbconfig processes in the past,
   usually after executing a shell function that does:
  
   | usbconfig_output=$(sudo usbconfig -d ${device} add_quirk 
   UQ_MSC_NO_INQUIRY)
   | [... error handling snipped ]
   | usbconfig_output=$(sudo usbconfig -d ${device} reset)
  
   Sometimes the second command seems to mess up the USB system.
 
  USB detach is synchronous. If for example umass fails to detach, due to 
  reference counts not reaching zero, that might be the root cause. Try to 
  get a backtrace from the usb_process() processes using kgdb, and 
  you'll see right away what is going on.
 
 Thanks for the quick response. So far I haven't been able to intentionally
 reproduce the issue, but I'll try the above the next time I unintentionally
 run into this again.

A couple of days ago usbconfig got stuck again:

fk@r500 ~ $sudo procstat -kk $(pgrep usbconfig)
  PIDTID COMM TDNAME   KSTACK   
 2444 100971 usbconfig-mi_switch+0xe1 sleepq_wait+0x3a 
_sx_xlock_hard+0x522 _sx_xlock+0x5d usbd_enum_lock+0x3a usb_ref_device+0x157 
usb_open+0xbf devfs_open+0x122 VOP_OPEN_APV+0xa1 vn_open_vnode+0x234 
vn_open_cred+0x310 kern_openat+0x26f amd64_syscall+0x3fd Xfast_syscall+0xfb 
 2425 100970 usbconfig-mi_switch+0xe1 
sleepq_timedwait+0x3a _sleep+0x294 pause_sbt+0xd0 usb_pause_mtx+0x85 
usb_ioctl+0x3e7 devfs_ioctl_f+0x13b kern_ioctl+0x3ce sys_ioctl+0x140 
amd64_syscall+0x3fd Xfast_syscall+0xfb 

The USB-related threads:

(kgdb) thread 520
[Switching to thread 520 (Thread 100970)]#0  sched_switch 
(td=0xf8001d2044a0, newtd=value optimized out, flags=value optimized 
out) at /usr/src/sys/kern/sched_ule.c:1940
1940cpuid = PCPU_GET(cpuid);
(kgdb) where
#0  sched_switch (td=0xf8001d2044a0, newtd=value optimized out, 
flags=value optimized out) at /usr/src/sys/kern/sched_ule.c:1940
#1  0x805bbf91 in mi_switch (flags=260, newtd=0x0) at 
/usr/src/sys/kern/kern_synch.c:492
#2  0x80601a7a in sleepq_timedwait (wchan=0x0, pri=0) at 
/usr/src/sys/kern/subr_sleepqueue.c:666
#3  0x805bb984 in _sleep (ident=value optimized out, lock=value 
optimized out, priority=value optimized out, wmesg=value optimized out, 
sbt=value optimized out, pr=value optimized out, 
flags=value optimized out) at /usr/src/sys/kern/kern_synch.c:250
#4  0x805bbe10 in pause_sbt (wmesg=value optimized out, sbt=value 
optimized out, pr=0, flags=value optimized out) at 
/usr/src/sys/kern/kern_synch.c:379
#5  0x81e2f175 in usb_pause_mtx (mtx=value optimized out, timo=value 
optimized out) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_util.c:143
#6  0x81e16ed7 in usb_ioctl (dev=value optimized out, cmd=value 
optimized out, addr=value optimized out, fflag=0, td=value optimized out)
at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_dev.c:1128
#7  0x8047cffb in devfs_ioctl_f (fp=0xf8001d3d1b40, com=2147767558, 
data=0xfe009453aa20, cred=value optimized out, td=0xf8001d2044a0) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:775
#8  0x8061041e in kern_ioctl (td=0xf8001d2044a0, fd=value 
optimized out, com=0) at file.h:318
#9  0x8060ffa0 in sys_ioctl (td=0xf8001d2044a0, 
uap=0xfe009453ab80) at /usr/src/sys/kern/sys_generic.c:718
#10 0x80877d5d in amd64_syscall (td=0xf8001d2044a0, traced=0) at 
subr_syscall.c:133
#11 0x8085ac9b in Xfast_syscall () at 
/usr/src/sys/amd64/amd64/exception.S:390
#12 0x000800b7caea in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb) thread 522
[Switching to thread 522 (Thread 100971)]#0  sched_switch 
(td=0xf8001d3a5940, newtd=value optimized out, flags=value optimized 
out) at /usr/src/sys/kern/sched_ule.c:1940
1940cpuid = PCPU_GET(cpuid);
(kgdb) where
#0  sched_switch (td=0xf8001d3a5940, newtd=value optimized out, 
flags=value optimized out) at /usr/src/sys/kern/sched_ule.c:1940
#1  0x805bbf91 in mi_switch (flags=260, newtd=0x0) at 
/usr/src/sys/kern/kern_synch.c:492
#2  0x8060126a in sleepq_wait (wchan=0x0, pri=0) at 
/usr/src/sys/kern/subr_sleepqueue.c:631
#3  0x805bae82 in _sx_xlock_hard (sx=0xf80015e82050, 
tid=18446735278106892608, opts=value optimized out, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:688
#4  0x805ba6ad in _sx_xlock (sx=0x0, opts=0, file=value optimized 
out, line=0) at sx.h:154
#5  0x81e19baa in usbd_enum_lock (udev=0xf80015e82000) at 
/usr/src/sys/modules/usb/usb/../../../dev/usb/usb_device.c:2755
#6  0x81e18967 in usb_ref_device (cpd

Re: geli: Wrong key with a simple passphrase. Doesn't handle the keyboard input

[Fabian Keil]

Aurelien Martin 01aurel...@gmail.com wrote:

 Is there people that can try to geli an external USB disk with a simple
 passphrase on CURRENT and tell me if the passphrase prompt shown the input,
 and if it's possible to attach it ?
 
 # uname -a
 FreeBSD  11.0-CURRENT FreeBSD 11.0-CURRENT #0 r271779: Fri Sep 19 01:18:53
 UTC 2014 r...@grind.freebsd.org:/usr/obj/arm.armv6/usr/src/sys/RPI-
 B  arm
 
 #kldstat
  21 0xc2e49000 17000geom_eli.ko
  31 0xc2e6 2a000crypto.ko
 
 
 # sysctl kern.geom.eli.visible_passphrase=1
 kern.geom.eli.visible_passphrase: 0 - 1
 
  Nothing print in the prompt 
 
 # geli init da0
 Enter new passphrase:
 Reenter new passphrase:

The sysctl only applies to the kernel, geli(8) doesn't use it.

  Impossible to attach the device with a simple passphrase. Tried 20x
 
 geli attach da0
 Enter passphrase:
 geli: Wrong key for da0

geli attach works for me on 11-CURRENT amd64, maybe it's an arm issue.

Fabian


pgpdEp6VcT5Qo.pgp
Description: OpenPGP digital signature

Re: sh: local assignment from command loses exit status

[Fabian Keil]

Eric van Gyzen e...@vangyzen.net wrote:

 On 11/06/2014 12:30, Fabian Keil wrote:
  Eric van Gyzen e...@vangyzen.net wrote:
 
  In sh, if I use a single statement to declare a local variable and
  assign the output of a command to it, the exit status of that command is
  lost.  For example:
 
  should_return_false() {
  local var1=`false`
  }
 
  The function should return non-zero, but it returns zero.
  The function should return the return code of the last command.
  In your example, the last command is local.
 
 Fair enough.  What about errexit?  The shell ran a command whose exit
 status was not tested, that status was failure, yet the shell did not exit.

That's unrelated to the local, though. Compare:

fk@r500 ~ $sh -e -c 'true `false; echo Not reached`; echo Reached'
Reached

While it's not obvious from the man page[1], my assumption is that this
is intentional behaviour. The return code of the command substitution
subshell can't be checked in the parent shell, as $? belongs to the
command that gets the output as argument (in your case local),
thus counting this as an untested return code would be inconvenient.

Fabian

[1] It could be argued that the behaviour is documented as
-e ... tends to behave in unexpected ways, though ...


pgpJVnYWbgvd6.pgp
Description: OpenPGP digital signature

Re: sh: local assignment from command loses exit status

[Fabian Keil]

Eric van Gyzen e...@vangyzen.net wrote:

 In sh, if I use a single statement to declare a local variable and
 assign the output of a command to it, the exit status of that command is
 lost.  For example:
 
 should_return_false() {
 local var1=`false`
 }
 
 The function should return non-zero, but it returns zero.

The function should return the return code of the last command.
In your example, the last command is local.

Fabian


pgpmCIsPJ20a6.pgp
Description: OpenPGP digital signature

Re: CTF: geom gate network patch

[Fabian Keil]

John-Mark Gurney j...@funkthat.com wrote:

 John-Mark Gurney wrote this message on Fri, Oct 17, 2014 at 09:58 -0700:
 
  I did some work at this a while back... and if you're interested in
  improving performance and willing to do some testing... I can send you
  some patches..
  
  There are a couple issues that I know about..
  
  First, ggate specificly sets the buffer sizes, which disables the
  autosizing of TCP's window.. This means that if you have a high latency,
  high bandwidth link, you'll be limited to 128k / rtt of bandwidth.
  
  Second is that ggate isn't issueing multiple IOs at a time.  This means
  that any NCQ or tagging isn't able to be used, where as when running
  natively they can be used...
 
 I've attached a patch I would like other ggate users to test and
 verify that there aren't bugs, or performance regressions by using
 this patch.
 
 The patch is also available at:
 https://www.funkthat.com/~jmg/patches/ggate.patch

I tested the patch on a recent 11-CURRENT system (ggatec/ggated)
and a 9.0-CURRENT system from 2009 (only ggated) and didn't notice
any problems.

The patch didn't seem to affect the performance either way,
but then again I'm using slow disks and ssh so I didn't expect
geom gate to be the bottle neck.

Fabian


pgpSuTNRvSM3g.pgp
Description: OpenPGP digital signature

Re: Order of geli passphrase prompt on boot

[Fabian Keil]

Miguel Clara miguelmcl...@gmail.com wrote:

 Sorry to bring this one back but I see no changes have been made to this in
 current.
 
 The issue is that USB devices are detected after the geli prompt and so the
 geli paraphrase prompt becomes hidden, and the simple solution would be
 to change the order the prompt show as in wait a few secs for the usb
 devices to be detected.

If you don't need any USB devices to boot, you can delay their
detection by loading the modules through /etc/rc.d/kld instead
of the loader:

fk@r500 ~ $grep kld /etc/rc.conf
kld_list=usb.ko usb_quirk.ko ehci.ko umass.ko

Fabian


pgpd6329GXoxZ.pgp
Description: OpenPGP digital signature

Re: Order of geli passphrase prompt on boot

[Fabian Keil]

Kurt Jaeger p...@opsec.eu wrote:

  If you don't need any USB devices to boot, you can delay their
  detection by loading the modules through /etc/rc.d/kld instead
  of the loader:
  
  fk@r500 ~ $grep kld /etc/rc.conf
  kld_list=usb.ko usb_quirk.ko ehci.ko umass.ko
 
 Does this really help with the GENERIC kernel ?

I didn't say it did. You need a kernel that doesn't already
contain the USB modules in /boot/kernel/kernel, this excludes
GENERIC kernels.

Fabian


pgphzo8bV6YHH.pgp
Description: OpenPGP digital signature

Re: Panic after USB deadlock followed by kldunload umass.ko

[Fabian Keil]

Hans Petter Selasky h...@selasky.org wrote:

 On 10/23/14 16:28, Fabian Keil wrote:

  kldunload umass.ko lead to a panic, dumping didn't work.
 
  Screenshots are available at:
  http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r273434-usb/
 
  I've seen locked-up usbconfig processes in the past,
  usually after executing a shell function that does:
 
  | usbconfig_output=$(sudo usbconfig -d ${device} add_quirk 
  UQ_MSC_NO_INQUIRY)
  | [... error handling snipped ]
  | usbconfig_output=$(sudo usbconfig -d ${device} reset)
 
  Sometimes the second command seems to mess up the USB system.

 USB detach is synchronous. If for example umass fails to detach, due to 
 reference counts not reaching zero, that might be the root cause. Try to 
 get a backtrace from the usb_process() processes using kgdb, and 
 you'll see right away what is going on.

Thanks for the quick response. So far I haven't been able to intentionally
reproduce the issue, but I'll try the above the next time I unintentionally
run into this again.

Fabian


signature.asc
Description: PGP signature

Panic after USB deadlock followed by kldunload umass.ko

[Fabian Keil]

A few days ago a couple of usbconfig processed did not exit:

fk@r500 ~ $sudo procstat -kk $(pgrep usbconfig)
  PIDTID COMM TDNAME   KSTACK   
 1624 100781 usbconfig-mi_switch+0xe1 sleepq_wait+0x3a 
_sx_xlock_hard+0x522 _sx_xlock+0x5d usbd_enum_lock+0x3a usb_ref_device+0x157 
usb_open+0xbf devfs_open+0x122 VOP_OPEN_APV+0xa1 vn_open_vnode+0x234 
vn_open_cred+0x351 kern_openat+0x26f amd64_syscall+0x3fb Xfast_syscall+0xfb 
 1617 100779 usbconfig-mi_switch+0xe1 sleepq_wait+0x3a 
_sx_xlock_hard+0x522 _sx_xlock+0x5d usbd_enum_lock+0x3a usb_ref_device+0x157 
usb_open+0xbf devfs_open+0x122 VOP_OPEN_APV+0xa1 vn_open_vnode+0x234 
vn_open_cred+0x351 kern_openat+0x26f amd64_syscall+0x3fb Xfast_syscall+0xfb 
 1615 100777 usbconfig-mi_switch+0xe1 sleepq_wait+0x3a 
_sx_xlock_hard+0x522 _sx_xlock+0x5d usbd_enum_lock+0x3a usb_ref_device+0x157 
usb_open+0xbf devfs_open+0x122 VOP_OPEN_APV+0xa1 vn_open_vnode+0x234 
vn_open_cred+0x351 kern_openat+0x26f amd64_syscall+0x3fb Xfast_syscall+0xfb 
 1601 100774 usbconfig-mi_switch+0xe1 
sleepq_timedwait+0x3a _sleep+0x294 pause_sbt+0xd0 usb_pause_mtx+0x85 
usb_ioctl+0x3e7 devfs_ioctl_f+0x13b kern_ioctl+0x3cd sys_ioctl+0x13c 
amd64_syscall+0x3fb Xfast_syscall+0xfb 

kldunload umass.ko lead to a panic, dumping didn't work.

Screenshots are available at:
http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r273434-usb/

I've seen locked-up usbconfig processes in the past,
usually after executing a shell function that does:

| usbconfig_output=$(sudo usbconfig -d ${device} add_quirk UQ_MSC_NO_INQUIRY)
| [... error handling snipped ]
| usbconfig_output=$(sudo usbconfig -d ${device} reset)

Sometimes the second command seems to mess up the USB system.

Fabian


signature.asc
Description: PGP signature

ZFS-related panic: possible spa-spa_errlog_lock deadlock

[Fabian Keil]

Using a kernel built from FreeBSD 11.0-CURRENT r271182 I got the following
panic yesterday:

[...]
Unread portion of the kernel message buffer:
[6880] panic: deadlkres: possible deadlock detected for 0xf80015289490, 
blocked for 1800503 ticks
[6880] 
[6880] cpuid = 1
[6880] KDB: stack backtrace:
[6880] db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 
0xfe009432e9e0
[6880] kdb_backtrace() at kdb_backtrace+0x39/frame 0xfe009432ea90
[6880] panic() at panic+0x1c1/frame 0xfe009432eb50
[6880] deadlkres() at deadlkres+0x588/frame 0xfe009432ebb0
[6880] fork_exit() at fork_exit+0x9a/frame 0xfe009432ebf0
[6880] fork_trampoline() at fork_trampoline+0xe/frame 0xfe009432ebf0
[6880] --- trap 0, rip = 0, rsp = 0xfe009432ecb0, rbp = 0 ---
[6880] KDB: enter: panic
[6880] Uptime: 1h54m40s
[6880] Dumping 354 out of 1973 
MB:..5%..14%..23%..32%..41%..55%..64%..73%..82%..91%

Reading symbols from /boot/kernel/zfs.ko.symbols...done.
[...]
Loaded symbols for /boot/kernel/profile.ko.symbols
#0  doadump (textdump=1) at pcpu.h:219
219 pcpu.h: No such file or directory.
in pcpu.h
(kgdb) where
#0  doadump (textdump=1) at pcpu.h:219
#1  0x80597bad in kern_reboot (howto=260) at 
/usr/src/sys/kern/kern_shutdown.c:447
#2  0x80598100 in panic (fmt=value optimized out) at 
/usr/src/sys/kern/kern_shutdown.c:746
#3  0x80539b98 in deadlkres () at /usr/src/sys/kern/kern_clock.c:240
#4  0x8055e8da in fork_exit (callout=0x80539610 deadlkres, 
arg=0x0, frame=0xfe009432ec00) at /usr/src/sys/kern/kern_fork.c:977
#5  0x8083fb5e in fork_trampoline () at 
/usr/src/sys/amd64/amd64/exception.S:605
#6  0x in ?? ()
Current language:  auto; currently minimal
(kgdb) set $td=(struct thread *)0xf80015289490
(kgdb) tid $td-td_tid
[Switching to thread 1184 (Thread 101428)]#0  sched_switch 
(td=0xf80015289490, newtd=value optimized out, flags=value optimized 
out) at /usr/src/sys/kern/sched_ule.c:1932
1932cpuid = PCPU_GET(cpuid);
(kgdb) bt
#0  sched_switch (td=0xf80015289490, newtd=value optimized out, 
flags=value optimized out) at /usr/src/sys/kern/sched_ule.c:1932
#1  0x805a23c1 in mi_switch (flags=260, newtd=0x0) at 
/usr/src/sys/kern/kern_synch.c:493
#2  0x805e4bca in sleepq_wait (wchan=0x0, pri=0) at 
/usr/src/sys/kern/subr_sleepqueue.c:631
#3  0x805a12b2 in _sx_xlock_hard (sx=0xf800062ed820, 
tid=18446735277971510416, opts=value optimized out, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:676
#4  0x805a0add in _sx_xlock (sx=0x0, opts=0, file=value optimized 
out, line=0) at sx.h:154
#5  0x8114a691 in spa_get_errlog_size (spa=0xf800062ed000) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa_errlog.c:142
#6  0x8113f549 in spa_get_stats (name=0xfe0006126000 spaceloop, 
config=0xfe00950e58e8, altroot=0xfe0006126430 , buflen=2048)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:3287
#7  0x81189a45 in zfs_ioc_pool_stats (zc=0xfe0006126000) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:1656
#8  0x81187290 in zfsdev_ioctl (dev=value optimized out, zcmd=value 
optimized out, arg=value optimized out, flag=value optimized out, 
td=value optimized out)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:6136
#9  0x80464a55 in devfs_ioctl_f (fp=0xf80017107f50, com=3222821381, 
data=0xf8004fb4b740, cred=value optimized out, td=0xf80015289490) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:757
#10 0x805f3c3d in kern_ioctl (td=0xf80015289490, fd=value 
optimized out, com=0) at file.h:311
#11 0x805f381c in sys_ioctl (td=0xf80015289490, 
uap=0xfe00950e5b80) at /usr/src/sys/kern/sys_generic.c:702
#12 0x8085c2db in amd64_syscall (td=0xf80015289490, traced=0) at 
subr_syscall.c:133
#13 0x8083f90b in Xfast_syscall () at 
/usr/src/sys/amd64/amd64/exception.S:390
#14 0x0008019fc3da in ?? ()
(kgdb) f 3
#3  0x805a12b2 in _sx_xlock_hard (sx=0xf800062ed820, 
tid=18446735277971510416, opts=value optimized out, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:676
676 sleepq_wait(sx-lock_object, 0);
(kgdb) p sx-lock_object
$14 = {lo_name = 0x81202163 spa-spa_errlog_lock, lo_flags = 
4096, lo_data = 0, lo_witness = 0x0}

This happened several minutes after a couple of zpool processes
stopped responding while accessing information about the following
pool:

fk@r500 ~ $zpool status -v spaceloop
  pool: spaceloop
 state: ONLINE
status: One or more devices has experienced an unrecoverable error.  An
attempt was made to correct the error.  Applications are unaffected.
action: Determine if the device needs to be replaced, and clear the errors
using 'zpool clear' or replace the device with 'zpool replace'.
   see: 

Re: ZFS-related panic: possible spa-spa_errlog_lock deadlock

[Fabian Keil]

Xin Li delp...@delphij.net wrote:

 On 9/7/14 9:02 PM, Fabian Keil wrote:
  Using a kernel built from FreeBSD 11.0-CURRENT r271182 I got the
  following panic yesterday:
  
  [...] Unread portion of the kernel message buffer: [6880] panic:
  deadlkres: possible deadlock detected for 0xf80015289490,
  blocked for 1800503 ticks
 
 Any chance to get all backtraces (e.g. thread apply all bt full 16)?
 I think a different thread that held the lock have been blocked,
 probably related to your disconnected vdev.

Output of thread apply all bt full 16 is available at:
http://www.fabiankeil.de/tmp/freebsd/kgdb-output-spa_errlog_lock-deadlock.txt

A lot of the backtraces prematurely end with Cannot access memory at address,
therefore I also added thread apply all bt output.

Apparently there are at least two additional threads blocking below 
spa_get_stats():

Thread 1182 (Thread 101989):
#0  sched_switch (td=0xf800628cc490, newtd=value optimized out, 
flags=value optimized out) at /usr/src/sys/kern/sched_ule.c:1932
#1  0x805a23c1 in mi_switch (flags=260, newtd=0x0) at 
/usr/src/sys/kern/kern_synch.c:493
#2  0x805e4bca in sleepq_wait (wchan=0x0, pri=0) at 
/usr/src/sys/kern/subr_sleepqueue.c:631
#3  0x80539f10 in _cv_wait (cvp=0xf80025534a50, 
lock=0xf80025534a30) at /usr/src/sys/kern/kern_condvar.c:139
#4  0x811721db in zio_wait (zio=value optimized out) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zio.c:1442
#5  0x81102111 in dbuf_read (db=value optimized out, zio=value 
optimized out, flags=value optimized out) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dbuf.c:649
#6  0x81108e6d in dmu_buf_hold (os=value optimized out, object=value 
optimized out, offset=value optimized out, tag=0x0, dbp=0xfe00955c6648, 
flags=value optimized out)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dmu.c:172
#7  0x81163986 in zap_lockdir (os=0xf8002b7ab000, obj=92, tx=0x0, 
lti=RW_READER, fatreader=1, adding=0, zapp=value optimized out)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zap_micro.c:467
#8  0x811644ad in zap_count (os=0x0, zapobj=0, 
count=0xfe00955c66d8) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zap_micro.c:712
#9  0x8114a6dc in spa_get_errlog_size (spa=0xf800062ed000) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa_errlog.c:149
---Type return to continue, or q return to quit---
#10 0x8113f549 in spa_get_stats (name=0xfe0044cac000 spaceloop, 
config=0xfe00955c68e8, altroot=0xfe0044cac430 , buflen=2048)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:3287
#11 0x81189a45 in zfs_ioc_pool_stats (zc=0xfe0044cac000) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:1656
#12 0x81187290 in zfsdev_ioctl (dev=value optimized out, zcmd=value 
optimized out, arg=value optimized out, flag=value optimized out, 
td=value optimized out)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:6136
#13 0x80464a55 in devfs_ioctl_f (fp=0xf80038bd00a0, com=3222821381, 
data=0xf800067b80a0, cred=value optimized out, td=0xf800628cc490) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:757
#14 0x805f3c3d in kern_ioctl (td=0xf800628cc490, fd=value 
optimized out, com=0) at file.h:311
#15 0x805f381c in sys_ioctl (td=0xf800628cc490, 
uap=0xfe00955c6b80) at /usr/src/sys/kern/sys_generic.c:702
#16 0x8085c2db in amd64_syscall (td=0xf800628cc490, traced=0) at 
subr_syscall.c:133
#17 0x8083f90b in Xfast_syscall () at 
/usr/src/sys/amd64/amd64/exception.S:390
#18 0x0008019fc3da in ?? ()
Previous frame inner to this frame (corrupt stack?)

Thread 1188 (Thread 102480):
#0  sched_switch (td=0xf80015a63920, newtd=value optimized out, 
flags=value optimized out) at /usr/src/sys/kern/sched_ule.c:1932
#1  0x805a23c1 in mi_switch (flags=260, newtd=0x0) at 
/usr/src/sys/kern/kern_synch.c:493
#2  0x805e4bca in sleepq_wait (wchan=0x0, pri=0) at 
/usr/src/sys/kern/subr_sleepqueue.c:631
#3  0x805a12b2 in _sx_xlock_hard (sx=0xf800062ed820, 
tid=18446735277979744544, opts=value optimized out, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:676
#4  0x805a0add in _sx_xlock (sx=0x0, opts=0, file=value optimized 
out, line=0) at sx.h:154
#5  0x8114a691 in spa_get_errlog_size (spa=0xf800062ed000) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa_errlog.c:142
#6  0x8113f549 in spa_get_stats (name=0xfe0005d6c000 spaceloop, 
config=0xfe0095f708e8, altroot=0xfe0005d6c430 , buflen=2048)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:3287
#7  0x81189a45 in zfs_ioc_pool_stats (zc=0xfe0005d6c000) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:1656
#8  0x81187290

Re: ZFS-related panic: possible spa-spa_errlog_lock deadlock

[Fabian Keil]

Xin Li delp...@delphij.net wrote:

 On 9/7/14 11:23 PM, Fabian Keil wrote:
  Xin Li delp...@delphij.net wrote:
  
  On 9/7/14 9:02 PM, Fabian Keil wrote:
  Using a kernel built from FreeBSD 11.0-CURRENT r271182 I got
  the following panic yesterday:
  
  [...] Unread portion of the kernel message buffer: [6880]
  panic: deadlkres: possible deadlock detected for
  0xf80015289490, blocked for 1800503 ticks
  
  Any chance to get all backtraces (e.g. thread apply all bt full
  16)? I think a different thread that held the lock have been
  blocked, probably related to your disconnected vdev.
  
  Output of thread apply all bt full 16 is available at: 
  http://www.fabiankeil.de/tmp/freebsd/kgdb-output-spa_errlog_lock-deadlock.txt
 
   A lot of the backtraces prematurely end with Cannot access memory
  at address, therefore I also added thread apply all bt output.
  
  Apparently there are at least two additional threads blocking below
  spa_get_stats():
[...]
 Yes, thread 1182 owned the lock and is waiting for the zio be done.
 Other threads that wanted the lock would have to wait.
 
 I don't have much clue why the system entered this state, however, as
 the operations should have errored out (the GELI device is gone on
 21:44:56 based on your log, which suggests all references were closed)
 instead of waiting.

It occurred to me that I have relevant auth.log entries as well:

Sep  6 20:54:31 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/geli attach -j - /dev/label/spaceloop
Sep  6 20:54:44 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/geli attach -j - /dev/label/takems
Sep  6 20:54:51 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zpool import -d /dev/label takems
Sep  6 20:55:30 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zfs send -i @2014-08-13_23:10 tank/home/fk@2014-09-06_19:56
Sep  6 20:55:30 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zfs receive -v -u -F spaceloop/backup/r500/tank/home/fk
Sep  6 20:55:46 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zfs send -i @2014-08-13_23:10 tank/home/fk@2014-09-06_19:56
Sep  6 20:55:46 r500 sudo:   fk : TTY=pts/5 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zfs receive -v -u -F spaceloop/backup/r500/tank/home/fk
[...]
Sep  6 21:28:47 r500 sudo:   fk : TTY=pts/6 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zpool status spaceloop
Sep  6 21:29:43 r500 sudo:   fk : TTY=pts/9 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zpool export takems
Sep  6 21:29:46 r500 sudo:   fk : TTY=pts/9 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/geli detach label/takems.eli
Sep  6 21:30:08 r500 sudo:   fk : TTY=pts/10 ; PWD=/home/fk ; USER=root ; 
COMMAND=/sbin/zpool clear spaceloop
Sep  6 21:44:16 r500 sudo:   fk : TTY=pts/11 ; PWD=/home/fk ; USER=root ; 
COMMAND=/usr/sbin/usbconfig
Sep  6 21:44:56 r500 sudo:   fk : TTY=pts/11 ; PWD=/home/fk ; USER=root ; 
COMMAND=/usr/sbin/usbconfig -d 1.3 reset
Sep  6 21:46:26 r500 sudo:   fk : TTY=pts/1 ; PWD=/home/fk ; USER=root ; 
COMMAND=/usr/sbin/usbconfig
Sep  6 22:03:33 r500 login: login on ttyv0 as fk

IIRC, I tried the USB reset because the zfs receive ... spaceloop/*,
zpool status spaceloop and zpool clear spaceloop processes (and some
that weren't called with sudo and thus weren't logged) got stuck and while
it caused the kernel to close label/spaceloop.eli as intended, it did not
noticeable affect the deadlocked processes.

I don't remember exactly why the same ZFS stream was sent twice, but the most
likely explanation seems to be that I aborted the operation before it was done
and it's conceivable that this left the system in a state that caused the second
attempt to get stuck.

Fabian


signature.asc
Description: PGP signature

getenv(TZ) crashes triggered by tzset_basic()

[Fabian Keil]

Using HEAD, www/gatling reproducible crashes for me after receiving
a single request if TZ isn't set:

(gdb) where
#0  strncmp (s1=optimized out, s2=optimized out, n=optimized out) at 
/usr/src/lib/libc/string/strncmp.c:46
#1  0x0008011a9ffe in strncmpeq (nameValue=0x7fffeb5e 
LC_PAPER=de_DE.UTF-8, name=0x8011be49e TZ, nameLen=optimized out) at 
/usr/src/lib/libc/stdlib/getenv.c:144
#2  __findenv_environ (name=optimized out, nameLen=optimized out) at 
/usr/src/lib/libc/stdlib/getenv.c:195
#3  getenv (name=0x8011be49e TZ) at /usr/src/lib/libc/stdlib/getenv.c:441
#4  0x000801189f49 in tzset_basic (rdlocked=0) at 
/usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1274
#5  0x00080118a13e in localtime (timep=0x801c12030) at 
/usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1467
#6  0x0040d38d in http_dirlisting (h=0x801c07140, D=0x801c0e080, 
path=0x7fffbb50 /, arg=0x0) at http.c:214
#7  0x0040ff9d in http_openfile (h=0x801c07140, filename=0x801c0c085 
/, ss=0x7fffc108, sockfd=9, nobody=1) at http.c:1485
#8  0x00413922 in httpresponse (h=0x801c07140, s=9, headerlen=76) at 
http.c:1940
#9  0x0040657d in handle_read_misc (i=9, h=0x801c07140, 
ftptimeout_secs=600, nextftp=...) at gatling.c:1051
#10 0x00404d54 in main (argc=3, argv=0x7fffe840, 
envp=0x7fffe860) at gatling.c:2247

This is not a recent regression, I first noticed it a couple
of months ago but haven't had time to look into it yet.

If was reminded of this because a program I'm working on
(Privoxy) recently crashed thusly:

(gdb) where
#0  0x00080128ef40 in strncmp (s1=optimized out, s2=optimized out, 
n=optimized out) at /usr/src/lib/libc/string/strncmp.c:46
#1  0x00080128bb92 in getenv (name=optimized out) at 
/usr/src/lib/libc/stdlib/getenv.c:424
#2  0x00080126bb39 in tzset_basic (rdlocked=0) at 
/usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1281
#3  0x00080126bb1b in tzset_basic (rdlocked=-14721152) at 
/usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1274
#4  0x00080122c0a0 in _fmt (format=0x22313031734e6863 Address 
0x22313031734e6863 out of bounds, t=0x8012a009e, pt=0x2 Address 0x2 out of 
bounds, ptlim=0xf5 Address 0xf5 out of bounds, 
warnp=0x8014cc418 tzname+8, loc=0x80126bb1b tzset_basic+27) at 
/usr/src/lib/libc/stdtime/strftime.c:137
#5  0x00080122d6fb in _conv (n=optimized out, format=optimized out, 
pt=optimized out, n=optimized out, format=optimized out, pt=optimized 
out, ptlim=optimized out)
at /usr/src/lib/libc/stdtime/strftime.c:597
#6  _yconv (a=optimized out, b=optimized out, convert_top=optimized out, 
convert_yy=optimized out, pt=optimized out, ptlim=optimized out, 
a=optimized out, b=optimized out, 
convert_top=optimized out, convert_yy=optimized out, pt=optimized 
out, ptlim=optimized out) at /usr/src/lib/libc/stdtime/strftime.c:649
#7  0x00428747 in get_log_timestamp (buffer=0x7f1f5f80 2014-06-30 
17:03:45.115, buffer_size=30) at errlog.c:482
[...]
(gdb) f 3
#3  0x00080126bb1b in tzset_basic (rdlocked=-14721152) at 
/usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1274
1274name = getenv(TZ);

I haven't been able to reproduce the Privoxy crash yet, but in case
of gatling the problem is reproducible and valgrind doesn't complain
about any previous memory corruption:

fk@r500 ~/test/privoxy/test $valgrind gatling -p 81
==6563== Memcheck, a memory error detector
==6563== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==6563== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==6563== Command: gatling -p 81
==6563== 
starting_up 0 :: 81
start_ftp 0 :: 2121
accept 7 10.0.0.1 48596 1 http
==6563== Invalid read of size 1
==6563==at 0x1039C74: strncmp (mc_replace_strmem.c:596)
==6563==by 0x1BA1FFD: getenv (getenv.c:144)
==6563==by 0x1B81F48: ??? (localtime.c:1274)
==6563==by 0x1B8213D: localtime (localtime.c:1467)
==6563==by 0x40D38C: http_dirlisting (http.c:214)
==6563==by 0x40FF9C: http_openfile (http.c:1485)
==6563==by 0x413921: httpresponse (http.c:1940)
==6563==by 0x40657C: handle_read_misc (gatling.c:1051)
==6563==by 0x404D53: main (gatling.c:2247)
==6563==  Address 0xff000b7a is not stack'd, malloc'd or (recently) free'd
==6563== 
==6563== 
==6563== Process terminating with default action of signal 11 (SIGSEGV): 
dumping core
==6563==  Access not within mapped region at address 0xFF000B7A
==6563==at 0x1039C74: strncmp (mc_replace_strmem.c:596)
==6563==by 0x1BA1FFD: getenv (getenv.c:144)
==6563==by 0x1B81F48: ??? (localtime.c:1274)
==6563==by 0x1B8213D: localtime (localtime.c:1467)
==6563==by 0x40D38C: http_dirlisting (http.c:214)
==6563==by 0x40FF9C: http_openfile (http.c:1485)
==6563==by 0x413921: httpresponse (http.c:1940)
==6563==by 0x40657C: handle_read_misc (gatling.c:1051)
==6563==by 0x404D53: main (gatling.c:2247)
==6563==  If you 

Re: getenv(TZ) crashes triggered by tzset_basic()

[Fabian Keil]

Trond Endrestøl trond.endres...@fagskolen.gjovik.no wrote:

 On Thu, 3 Jul 2014 14:01+0200, Fabian Keil wrote:
 
  Using HEAD, www/gatling reproducible crashes for me after receiving
  a single request if TZ isn't set:
  
  (gdb) where
  #0  strncmp (s1=optimized out, s2=optimized out, n=optimized out) at 
  /usr/src/lib/libc/string/strncmp.c:46
  #1  0x0008011a9ffe in strncmpeq (nameValue=0x7fffeb5e 
  LC_PAPER=de_DE.UTF-8, name=0x8011be49e TZ, nameLen=optimized out) at 
  /usr/src/lib/libc/stdlib/getenv.c:144
  #2  __findenv_environ (name=optimized out, nameLen=optimized out) at 
  /usr/src/lib/libc/stdlib/getenv.c:195
  #3  getenv (name=0x8011be49e TZ) at /usr/src/lib/libc/stdlib/getenv.c:441
  #4  0x000801189f49 in tzset_basic (rdlocked=0) at 
  /usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1274
  #5  0x00080118a13e in localtime (timep=0x801c12030) at 
  /usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1467
  #6  0x0040d38d in http_dirlisting (h=0x801c07140, D=0x801c0e080, 
  path=0x7fffbb50 /, arg=0x0) at http.c:214
  #7  0x0040ff9d in http_openfile (h=0x801c07140, 
  filename=0x801c0c085 /, ss=0x7fffc108, sockfd=9, nobody=1) at 
  http.c:1485
  #8  0x00413922 in httpresponse (h=0x801c07140, s=9, headerlen=76) 
  at http.c:1940
  #9  0x0040657d in handle_read_misc (i=9, h=0x801c07140, 
  ftptimeout_secs=600, nextftp=...) at gatling.c:1051
  #10 0x00404d54 in main (argc=3, argv=0x7fffe840, 
  envp=0x7fffe860) at gatling.c:2247
  
  This is not a recent regression, I first noticed it a couple
  of months ago but haven't had time to look into it yet.
  
  If was reminded of this because a program I'm working on
  (Privoxy) recently crashed thusly:
  
  (gdb) where
  #0  0x00080128ef40 in strncmp (s1=optimized out, s2=optimized out, 
  n=optimized out) at /usr/src/lib/libc/string/strncmp.c:46
  #1  0x00080128bb92 in getenv (name=optimized out) at 
  /usr/src/lib/libc/stdlib/getenv.c:424
  #2  0x00080126bb39 in tzset_basic (rdlocked=0) at 
  /usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1281
  #3  0x00080126bb1b in tzset_basic (rdlocked=-14721152) at 
  /usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1274
  #4  0x00080122c0a0 in _fmt (format=0x22313031734e6863 Address 
  0x22313031734e6863 out of bounds, t=0x8012a009e, pt=0x2 Address 0x2 out 
  of bounds, ptlim=0xf5 Address 0xf5 out of bounds, 
  warnp=0x8014cc418 tzname+8, loc=0x80126bb1b tzset_basic+27) at 
  /usr/src/lib/libc/stdtime/strftime.c:137
  #5  0x00080122d6fb in _conv (n=optimized out, format=optimized out, 
  pt=optimized out, n=optimized out, format=optimized out, 
  pt=optimized out, ptlim=optimized out)
  at /usr/src/lib/libc/stdtime/strftime.c:597
  #6  _yconv (a=optimized out, b=optimized out, convert_top=optimized 
  out, convert_yy=optimized out, pt=optimized out, ptlim=optimized 
  out, a=optimized out, b=optimized out, 
  convert_top=optimized out, convert_yy=optimized out, pt=optimized 
  out, ptlim=optimized out) at /usr/src/lib/libc/stdtime/strftime.c:649
  #7  0x00428747 in get_log_timestamp (buffer=0x7f1f5f80 
  2014-06-30 17:03:45.115, buffer_size=30) at errlog.c:482
  [...]
  (gdb) f 3
  #3  0x00080126bb1b in tzset_basic (rdlocked=-14721152) at 
  /usr/src/lib/libc/../../contrib/tzcode/stdtime/localtime.c:1274
 
  1274name = getenv(TZ);
 
 Does the code test at all for the possibility of getenv(3) returning a 
 NULL pointer?

It does:
http://svnweb.freebsd.org/base/head/contrib/tzcode/stdtime/localtime.c?view=markup#l1270

Assuming the back traces aren't corrupted, the crashes occur
before getenv() returns, though.

Fabian


signature.asc
Description: PGP signature

Re: Ordering for network-sensitive rc scripts

[Fabian Keil]

David Chisnall thera...@freebsd.org wrote:

 On 11 May 2014, at 20:23, Adrian Chadd adr...@freebsd.org wrote:
 
  On 11 May 2014 12:01, David Chisnall thera...@freebsd.org wrote:
  On 17 Apr 2014, at 09:30, Adrian Chadd adr...@freebsd.org wrote:
  
  Can't we add a devd hook to do that?
  
  I tried doing this, but it turns out that wlan devices don't appear to 
  send devd LINK_UP / LINK_DOWN events.  It would be nice to have a clean 
  solution to this.  By default, using the stock rc scripts, my router is 
  currently not able to forward packets from the WiFi until I've logged into 
  it and manually run 'service pf restart', which is a bit crazy.  I've 
  hacked around it by having a script run from rc.local that sleeps for 60 
  seconds and then restarts a few things, but that's really, really ugly.
  
  On closer inspection, pf doesn't fail silently, it complains about a 
  syntax error in my config file because wlan0 is not a known interface.
  
  We therefore have an rc ordering problem if you want to use pf and WiFi at 
  the same time.  This problem was introduced some time between 9.2 and 10.0.
  
  Is there a PR for this? It's the first I've heard of it.
 
 Not yet.  This is the result of my investigations as of 10 minutes ago.  I'll 
 file a PR, if no one can tell me I'm doing something obviously wrong...

I'm not saying that you did something wrong or shouldn't file a PR,
but on my laptop (11-CURRENT) pf works as expected without service
restarts.

The relevant configuration excerpt:

ext_if  = wlan0
int_if  = bge0
jail_if = lo1
[...]
nat pass on $ext_if from  $int_if:network to any - $ext_if
nat on $ext_if from $jail_if:network to any - $ext_if

wlan0 is a wlandev on iwn0.

I'm usually using static IP addresses, but it worked with dynamic
IP addresses (and ext_if and int_if reversed) in the past.

Fabian


signature.asc
Description: PGP signature

Re: Fatal double fault in ZFS with yesterday's CURRENT

[Fabian Keil]

Steven Hartland kill...@multiplay.co.uk wrote:

  Steven Hartland kill...@multiplay.co.uk wrote:
  
   From: Fabian Keil freebsd-lis...@fabiankeil.de
   
After updating my laptop to yesterday's CURRENT (r265216),
I got the following fatal double fault on boot:
http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r265216/

My previous kernel was based on r264721.
   
I'm using a couple of custom patches, some of them are ZFS-related
and thus may be part of the problem (but worked fine for months).
I'll try to reproduce the panic without the patches tomorrow.
   
   
   Your seeing a stack overflow in the new ZFS queuing code, which I
   believe is being triggered by lack of support for TRIM in one of
   your devices, something Xin reported to me yesterday.
   
   I commited a fix for failing TRIM requests processing slowly last
   night so you could try updating to after r265253 and see if that
   helps.
  
  Thanks. The hard disk is indeed unlikely to support TRIM requests,
  but I can still reproduce the problem with a kernel based on r265255.
 
 Thanks for testing, I suspect its still a numbers game with how many items
 are outstanding in the queue and now that free / TRIM requests are also
 now queued its triggering the failure.
 
 If your just on a HDD try setting the following in /boot/loader.conf as
 a temporary workaround:
 vfs.zfs.trim.enabled=0

That worked, thanks.

   I still need to investigate the stack overflow more directly which
   appears to be caused by the new zfs queuing code when things are
   running slowly and there's a large backlog of IO's.
  
   I would be interested to know you config there so zpool layout and
   hardware in the mean time.
  
  The system is a Lenovo ThinkPad R500:
  http://www.nycbug.org/index.cgi?action=dmesgddo=viewdmesgid=2449
  
  I'm booting from UFS, the panic occurs while the pool is being imported.
  
  The pool is located on a single geli-encrypted slice:
  
  fk@r500 ~ $zpool status tank
pool: tank
   state: ONLINE
scan: scrub repaired 0 in 4h11m with 0 errors on Sat Mar 22 18:25:01 2014
  config:
  
   NAME   STATE READ WRITE CKSUM
   tank   ONLINE   0 0 0
 ada0s1d.eli  ONLINE   0 0 0
  
  errors: No known data errors
  
  Maybe geli fails TRIM requests differently.
 
 That helps, Xin also reported the issue with geli and thats what I'm testing
 with, I believe this is a factor because is significantly slows things down
 again meaning more items in the queues, but I've only managed to trigger it
 once here as the machine I'm using is pretty quick.

It probably doesn't make a difference, but my system is rather old
and thus I'm still using geli version 3 for ada0s1d.eli while
geli init nowadays defaults to geli version 7.

The system certainly is also slow, though.

Fabian


signature.asc
Description: PGP signature

Re: Fatal double fault in ZFS with yesterday's CURRENT [SOLVED]

[Fabian Keil]

Steven Hartland kill...@multiplay.co.uk wrote:

 Thanks for your help testing this Fabian, I've now committed the fix for
 this for this:
 http://svnweb.freebsd.org/changeset/base/265321

Thanks a lot, Steve.

Fabian


signature.asc
Description: PGP signature

Fatal double fault in ZFS with yesterday's CURRENT

[Fabian Keil]

After updating my laptop to yesterday's CURRENT (r265216),
I got the following fatal double fault on boot:
http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r265216/

My previous kernel was based on r264721.

I'm using a couple of custom patches, some of them are ZFS-related
and thus may be part of the problem (but worked fine for months).
I'll try to reproduce the panic without the patches tomorrow.

Fabian


signature.asc
Description: PGP signature

Re: Fatal double fault in ZFS with yesterday's CURRENT

[Fabian Keil]

Steven Hartland kill...@multiplay.co.uk wrote:

 From: Fabian Keil freebsd-lis...@fabiankeil.de
 
  After updating my laptop to yesterday's CURRENT (r265216),
  I got the following fatal double fault on boot:
  http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r265216/
  
  My previous kernel was based on r264721.
 
  I'm using a couple of custom patches, some of them are ZFS-related
  and thus may be part of the problem (but worked fine for months).
  I'll try to reproduce the panic without the patches tomorrow.
 
 
 Your seeing a stack overflow in the new ZFS queuing code, which I
 believe is being triggered by lack of support for TRIM in one of
 your devices, something Xin reported to me yesterday.
 
 I commited a fix for failing TRIM requests processing slowly last
 night so you could try updating to after r265253 and see if that
 helps.

Thanks. The hard disk is indeed unlikely to support TRIM requests,
but I can still reproduce the problem with a kernel based on r265255.

 I still need to investigate the stack overflow more directly which
 appears to be caused by the new zfs queuing code when things are
 running slowly and there's a large backlog of IO's.

 I would be interested to know you config there so zpool layout and
 hardware in the mean time.

The system is a Lenovo ThinkPad R500:
http://www.nycbug.org/index.cgi?action=dmesgddo=viewdmesgid=2449

I'm booting from UFS, the panic occurs while the pool is being imported.

The pool is located on a single geli-encrypted slice:

fk@r500 ~ $zpool status tank
  pool: tank
 state: ONLINE
  scan: scrub repaired 0 in 4h11m with 0 errors on Sat Mar 22 18:25:01 2014
config:

NAME   STATE READ WRITE CKSUM
tank   ONLINE   0 0 0
  ada0s1d.eli  ONLINE   0 0 0

errors: No known data errors

Maybe geli fails TRIM requests differently.

Fabian


signature.asc
Description: PGP signature

Re: claws-mail deadlocking in iconv

[Fabian Keil]

Fabian Keil freebsd-lis...@fabiankeil.de wrote:

 After the iconv import claws-mail started to deadlock in iconv every now
 and then on my system, which prevented claws-mail from rendering windows
 or reacting to input.
[...] 
 Did anyone else run into this or can comment on the patch or
 the backtraces?

Thanks for the feedback, everyone. This is now bin/182994:
http://www.freebsd.org/cgi/query-pr.cgi?pr=182994

Fabian


signature.asc
Description: PGP signature

claws-mail deadlocking in iconv

[Fabian Keil]

After the iconv import claws-mail started to deadlock in iconv every now
and then on my system, which prevented claws-mail from rendering windows
or reacting to input.

So far I haven't been able to reproduce this intentionally and various
rebuilds of ports, kernel and userland (mainly for other reasons) had
no effect.

When the problem occurs, trying to attach to the process causes
gdb and gdb76 to crash which also crashes claws-mail, but sending
SIGABRT causes a proper core dump that can be analysed with gdb.

The backtraces always show that there is only one thread running and
it's trying to lock cm_lock in _citrus_mapper_close(), which apparently
is already locked due to a _citrus_mapper_close() recursion. Examples:

#0  _umtx_op_err () at /usr/src/lib/libthr/arch/amd64/amd64/_umtx_op_err.S:37
37  RSYSCALL_ERR(_umtx_op)
[New Thread 80a806400 (LWP 100487/claws-mail)]
(gdb) where
#0  _umtx_op_err () at /usr/src/lib/libthr/arch/amd64/amd64/_umtx_op_err.S:37
#1  0x0008084861a6 in __thr_rwlock_wrlock (rwlock=0x80a8a47c0, tsp=value 
optimized out) at /usr/src/lib/libthr/thread/thr_umtx.c:296
#2  0x000808489b1d in rwlock_wrlock_common (rwlock=value optimized out, 
abstime=0x0) at /usr/src/lib/libthr/thread/thr_rwlock.c:267
#3  0x000808489a8b in _pthread_rwlock_wrlock (rwlock=0x80a8a47c0) at 
/usr/src/lib/libthr/thread/thr_rwlock.c:289
#4  0x00080911e848 in _citrus_mapper_close (cm=0x80b5a2d80) at 
/usr/src/lib/libc/iconv/citrus_mapper.c:375
#5  0x00080d205d18 in _citrus_mapper_serial_mapper_uninit (cm=0x80b5a2d40) 
at 
/usr/src/lib/libiconv_modules/mapper_parallel/../mapper_serial/citrus_mapper_serial.c:110
#6  0x00080911e8d7 in mapper_close (cm=0x80b5a2d40) at 
/usr/src/lib/libc/iconv/citrus_mapper.c:188
#7  0x00080911e88c in _citrus_mapper_close (cm=value optimized out) at 
/usr/src/lib/libc/iconv/citrus_mapper.c:384
#8  0x00080c4e83f3 in close_srcs (sl=0x80b591140) at 
/usr/src/lib/libiconv_modules/iconv_std/citrus_iconv_std.c:206
#9  0x00080c4e7dc9 in _citrus_iconv_std_iconv_uninit_shared (ci=value 
optimized out) at 
/usr/src/lib/libiconv_modules/iconv_std/citrus_iconv_std.c:415
#10 0x0008090f3f95 in release_shared (ci=0x80a8ee630) at 
/usr/src/lib/libc/iconv/citrus_iconv.c:99
#11 0x0008090f4002 in _citrus_iconv_close (cv=0x80d88d5d0) at 
/usr/src/lib/libc/iconv/citrus_iconv.c:335
#12 0x0008090f1ca6 in iconv_close (handle=0x80a8a47c0) at 
/usr/src/lib/libc/iconv/iconv.c:131
#13 0x0046376d in conv_iconv_strdup (inbuf=0x7fff58b0 \n, 
src_code=0x80b5b4db0 Windows-1252, dest_code=0x6f03d0 UTF-8) at 
codeconv.c:895
#14 0x00463d13 in conv_convert (conv=0x80b5a4e80, outbuf=0x7fff3720 
, outlen=8192, inbuf=0x7fff58b0 \n) at codeconv.c:734
#15 0x005e22ac in textview_write_line (textview=0x80a959cc0, 
str=0x7fff58b0 \n, conv=0x80b5a4e80, do_quote_folding=1) at 
textview.c:1573
#16 0x005df8e4 in textview_write_body (textview=0x80a959cc0, 
mimeinfo=0x80aad2d00) at textview.c:1177
#17 0x005e5363 in textview_add_part (textview=0x80a959cc0, 
mimeinfo=0x80aad2d00) at textview.c:826
#18 0x005e4053 in recursive_add_parts (textview=0x80a959cc0, 
node=0x80a826190) at textview.c:839
#19 0x005e4302 in recursive_add_parts (textview=0x80a959cc0, 
node=0x80aa81d20) at textview.c:888
#20 0x005e4302 in recursive_add_parts (textview=0x80a959cc0, 
node=0x80a828890) at textview.c:888
#21 0x005defa1 in textview_add_parts (textview=0x80a959cc0, 
mimeinfo=0x80b610700) at textview.c:898
#22 0x005deb85 in textview_show_part (textview=0x80a959cc0, 
mimeinfo=0x80b610700, fp=0x8094319a0) at textview.c:645
[...]

#0  0x000808491b9c in __error () from /lib/libthr.so.3
#1  0x00080848bb1d in rwlock_wrlock_common (rwlock=value optimized out, 
abstime=0x0) at /usr/src/lib/libthr/thread/thr_rwlock.c:267
#2  0x00080848ba8b in _pthread_rwlock_wrlock (rwlock=0x80a8ede20) at 
/usr/src/lib/libthr/thread/thr_rwlock.c:289
#3  0x00080911f848 in _citrus_mapper_close (cm=0x80a8bfc40) at 
/usr/src/lib/libc/iconv/citrus_mapper.c:375
#4  0x00080ce02d18 in _citrus_mapper_serial_mapper_uninit (cm=0x80a8bfc00) 
at 
/usr/src/lib/libiconv_modules/mapper_parallel/../mapper_serial/citrus_mapper_serial.c:110
#5  0x00080911f8d7 in mapper_close (cm=0x80a8bfc00) at 
/usr/src/lib/libc/iconv/citrus_mapper.c:188
#6  0x00080911f88c in _citrus_mapper_close (cm=value optimized out) at 
/usr/src/lib/libc/iconv/citrus_mapper.c:384
#7  0x00080c5893f3 in close_srcs (sl=0x80a8edda0) at 
/usr/src/lib/libiconv_modules/iconv_std/citrus_iconv_std.c:206
#8  0x00080c588dc9 in _citrus_iconv_std_iconv_uninit_shared (ci=value 
optimized out) at 
/usr/src/lib/libiconv_modules/iconv_std/citrus_iconv_std.c:415
#9  0x0008090f4f95 in release_shared (ci=0x80b408890) at 
/usr/src/lib/libc/iconv/citrus_iconv.c:99
#10 0x0008090f5002 in _citrus_iconv_close (cv=0x80b782630) at 

Re: [RFC][CFT] GEOM direct dispatch and fine-grained CAM locking

[Fabian Keil]

Alexander Motin m...@freebsd.org wrote:

 I would like to invite more people to review and test my patches for 
 improving CAM and GEOM scalability, that for last six months you could 
 see developing in project/camlock SVN branch. Full diff of that branch 
 against present head (r255131) can be found here:
 http://people.freebsd.org/~mav/camlock_patches/camlock_20130902.patch

So far I haven't noticed any issues with this patch (or later on with
camlock_20130906.patch) using glabel, ggatec, geli and ZFS on amd64.
cdda2wav continued to work as expected as well.

Fabian


signature.asc
Description: PGP signature

Re: Improved SYN Cookies: Looking for testers

[Fabian Keil]

Andre Oppermann an...@freebsd.org wrote:

 On 12.07.2013 12:56, Fabian Keil wrote:
  Andre Oppermann an...@freebsd.org wrote:
 
  On 10.07.2013 15:18, Fabian Keil wrote:
  Andre Oppermann an...@freebsd.org wrote:
 
  It will give a bit of debug log output which is it telling you mostly about
  rounding to the next nearest index value.  You can send the output 
  privately
  to me to spot unexpected outliers, if any.
 
  One unexpected outlier seems to be:
 
 Both errors are normal and a sign of lazy application behavior, not a TCP
 error.

Thanks for the explanation. Makes sense.

Fabian


signature.asc
Description: PGP signature

Re: Improved SYN Cookies: Looking for testers

[Fabian Keil]

Andre Oppermann an...@freebsd.org wrote:

 On 10.07.2013 15:18, Fabian Keil wrote:
  Andre Oppermann an...@freebsd.org wrote:
 
  We have a SYN cookie implementation for quite some time now but it
  has some limitations with current realities for window scaling and
  SACK encoding the in the few available bits.
[...]
 http://people.freebsd.org/~andre/syncookie-20130708.diff
 
  I've been using the patch for a couple of days and didn't notice any
  issues so far. Privoxy's regression tests continue to work as expected
  as well.
 
 Thanks for testing and reporting back.
 
 Could you test with net.inet.tcp.log_debug and net.inet.tcp.syncookies_only=1
 as well to bypass the syn cache entirely?

I haven't noticed any issues with net.inet.tcp.syncookies_only=1.

 It will give a bit of debug log output which is it telling you mostly about
 rounding to the next nearest index value.  You can send the output privately
 to me to spot unexpected outliers, if any.

One unexpected outlier seems to be:

Jul 11 12:42:51 r500 kernel: [10947] TCP: [10.0.0.1]:62972 to [10.0.0.1]:8118 
tcpflags 0x18PUSH,ACK; tcp_do_segment: FIN_WAIT_2: Received 27 bytes of data 
after socket was closed, sending RST and removing tcpcb
Jul 11 12:42:51 r500 kernel: [10947] TCP: [10.0.0.1]:62972 to [10.0.0.1]:8118 
tcpflags 0x11FIN,ACK; syncache_expand: Segment failed SYNCOOKIE 
authentication, segment rejected (probably spoofed)

This also seems to have resulted in two reset packets:

fk@r500 ~/test/wireshark $tcpdump -vv -n -r syncookie-test.pcap  dst port 62972
reading from file syncookie-test.pcap, link-type NULL (BSD loopback)
12:42:47.033832 IP (tos 0x0, ttl 64, id 17522, offset 0, flags [DF], proto TCP 
(6), length 60, bad cksum 0 (-e248)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [S.], cksum 0x8c5f (correct), seq 
1633309846, ack 61471870, win 65535, options [mss 16344,nop,wscale 6,sackOK,TS 
val 4243589075 ecr 4051741531], length 0
12:42:47.138107 IP (tos 0x0, ttl 64, id 17582, offset 0, flags [DF], proto TCP 
(6), length 52, bad cksum 0 (-e214)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [.], cksum 0xef2f (correct), seq 1, 
ack 183, win 1275, options [nop,nop,TS val 4243589180 ecr 4051741536], length 0
12:42:47.785762 IP (tos 0x0, ttl 64, id 17592, offset 0, flags [DF], proto TCP 
(6), length 120, bad cksum 0 (-e1c6)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [P.], cksum 0x7209 (correct), seq 
1:69, ack 183, win 1275, options [nop,nop,TS val 4243589827 ecr 4051741536], 
length 68
12:42:47.945156 IP (tos 0x0, ttl 64, id 17609, offset 0, flags [DF], proto TCP 
(6), length 52, bad cksum 0 (-e1f9)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [.], cksum 0xe80f (correct), seq 69, 
ack 325, win 1275, options [nop,nop,TS val 4243589987 ecr 4051742343], length 0
12:42:48.470035 IP (tos 0x0, ttl 64, id 17678, offset 0, flags [DF], proto TCP 
(6), length 550, bad cksum 0 (-dfc2)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [P.], cksum 0x3ce0 (correct), seq 
69:567, ack 325, win 1275, options [nop,nop,TS val 4243590511 ecr 4051742343], 
length 498
12:42:48.599754 IP (tos 0x0, ttl 64, id 17683, offset 0, flags [DF], proto TCP 
(6), length 550, bad cksum 0 (-dfbd)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [P.], cksum 0x0a10 (correct), seq 
567:1065, ack 325, win 1275, options [nop,nop,TS val 4243590641 ecr 
4051743067], length 498
12:42:48.699161 IP (tos 0x0, ttl 64, id 17688, offset 0, flags [DF], proto TCP 
(6), length 2465, bad cksum 0 (-d83d)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [P.], cksum 0x92bd (correct), seq 
1065:3478, ack 325, win 1275, options [nop,nop,TS val 4243590741 ecr 
4051743197], length 2413
12:42:48.824428 IP (tos 0x0, ttl 64, id 17706, offset 0, flags [DF], proto TCP 
(6), length 52, bad cksum 0 (-e198)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [.], cksum 0xd2da (correct), seq 
3478, ack 592, win 1275, options [nop,nop,TS val 4243590867 ecr 4051743216], 
length 0
12:42:48.924148 IP (tos 0x0, ttl 64, id 17713, offset 0, flags [DF], proto TCP 
(6), length 52, bad cksum 0 (-e191)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [.], cksum 0xd1dd (correct), seq 
3478, ack 639, win 1275, options [nop,nop,TS val 4243590966 ecr 4051743323], 
length 0
12:42:49.725732 IP (tos 0x0, ttl 64, id 17769, offset 0, flags [DF], proto TCP 
(6), length 99, bad cksum 0 (-e12a)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [P.], cksum 0x7969 (correct), seq 
3478:3525, ack 639, win 1275, options [nop,nop,TS val 4243591767 ecr 
4051743323], length 47
12:42:49.833378 IP (tos 0x0, ttl 64, id 17784, offset 0, flags [DF], proto TCP 
(6), length 52, bad cksum 0 (-e14a)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [.], cksum 0xc9a7 (correct), seq 
3525, ack 882, win 1275, options [nop,nop,TS val 4243591876 ecr 4051744225], 
length 0
12:42:50.436702 IP (tos 0x0, ttl 64, id 17801, offset 0, flags [DF], proto TCP 
(6), length 550, bad cksum 0 (-df47)!)
10.0.0.1.8118  10.0.0.1.62972: Flags [P.], cksum 0x3f05 (correct), seq 
3525:4023, ack 882, win 1275

Re: Improved SYN Cookies: Looking for testers

[Fabian Keil]

Andre Oppermann an...@freebsd.org wrote:

 We have a SYN cookie implementation for quite some time now but it
 has some limitations with current realities for window scaling and
 SACK encoding the in the few available bits.
 
 This patch updates and improves SYN cookies mainly by:
 
   a) encoding of MSS, WSCALE (window scaling) and SACK into the ISN
  (initial sequence number) without the use of timestamp bits.
 
   b) switching to the very fast and cryptographically strong SipHash-2-4
  hash MAC algorithm to protect the SYN cookie against forgery.
 
 The patch had been reviewed by dwmalone (cookies) and cperciva (siphash).
 
 Please find it here for testing:
 
   http://people.freebsd.org/~andre/syncookie-20130708.diff

I've been using the patch for a couple of days and didn't notice any
issues so far. Privoxy's regression tests continue to work as expected
as well.

BTW, I think kern/173309 could be closed.

Fabian


signature.asc
Description: PGP signature

panic: solaris assert: sa.sa_magic == 0x2F505A (0x4d5ea364 == 0x2f505a), file: /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c, line: 625

[Fabian Keil]

I got the following panic on 10.0-CURRENT from two days ago
while receiving an incremental snapshot to a certain pool:

(kgdb) where
#0  doadump (textdump=0) at pcpu.h:229
#1  0x8031a3ce in db_dump (dummy=value optimized out, dummy2=0, 
dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:543
#2  0x80319eca in db_command (last_cmdp=value optimized out, 
cmd_table=value optimized out, dopager=1) at /usr/src/sys/ddb/db_command.c:449
#3  0x80319c82 in db_command_loop () at 
/usr/src/sys/ddb/db_command.c:502
#4  0x8031c5d0 in db_trap (type=value optimized out, code=0) at 
/usr/src/sys/ddb/db_main.c:231
#5  0x805d0da3 in kdb_trap (type=3, code=0, tf=value optimized out) 
at /usr/src/sys/kern/subr_kdb.c:654
#6  0x8087fdc3 in trap (frame=0xff80dc9d6520) at 
/usr/src/sys/amd64/amd64/trap.c:579
#7  0x80869cb2 in calltrap () at exception.S:228
#8  0x805d058e in kdb_enter (why=0x80a47e7a panic, msg=value 
optimized out) at cpufunc.h:63
#9  0x80599216 in panic (fmt=value optimized out) at 
/usr/src/sys/kern/kern_shutdown.c:747
#10 0x8130323f in assfail3 (a=value optimized out, lv=value 
optimized out, op=value optimized out, rv=value optimized out, f=value 
optimized out, l=value optimized out)
at 
/usr/src/sys/modules/opensolaris/../../cddl/compat/opensolaris/kern/opensolaris_cmn_err.c:89
#11 0x8117924e in zfs_space_delta_cb (bonustype=value optimized out, 
data=0xff8015eeb8c0, userp=0xfe004261c640, groupp=0xfe004261c648)
at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c:625
#12 0x8110003b in dmu_objset_userquota_get_ids (dn=0xfe004261c358, 
before=0, tx=value optimized out) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:1249
#13 0x811071b6 in dnode_sync (dn=0xfe004261c358, 
tx=0xfe00186e1300) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dnode_sync.c:554
#14 0x810ff98b in dmu_objset_sync_dnodes (list=0xfe00691a5250, 
newlist=value optimized out, tx=value optimized out)
at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:910
#15 0x810ff825 in dmu_objset_sync (os=0xfe00691a5000, pio=value 
optimized out, tx=0xfe00186e1300)
at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:1027
#16 0x8110cb0d in dsl_dataset_sync (ds=0xfe001f3d0c00, zio=0x780, 
tx=0xfe00186e1300) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dsl_dataset.c:1411
#17 0x8111399a in dsl_pool_sync (dp=0xfe0069ec4000, txg=value 
optimized out) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dsl_pool.c:409
#18 0x8112f0ee in spa_sync (spa=0xfe0050f0, txg=3292) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:6328
#19 0x81137c45 in txg_sync_thread (arg=0xfe0069ec4000) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/txg.c:493
#20 0x80569c1a in fork_exit (callout=0x811378d0 
txg_sync_thread, arg=0xfe0069ec4000, frame=0xff80dc9d6c00) at 
/usr/src/sys/kern/kern_fork.c:991
#21 0x8086a1ee in fork_trampoline () at exception.S:602
#22 0x in ?? ()
Current language:  auto; currently minimal
(kgdb) f 12
#12 0x8110003b in dmu_objset_userquota_get_ids (dn=0xfe004261c358, 
before=0, tx=value optimized out) at 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:1249
1249error = used_cbs[os-os_phys-os_type](dn-dn_bonustype, data,
(kgdb) p *dn
$1 = {dn_struct_rwlock = {lock_object = {lo_name = 0x811da0a9 
dn-dn_struct_rwlock, lo_flags = 4096, lo_data = 0, lo_witness = 0x0}, 
sx_lock = 1}, dn_link = {list_next = 0xfe0042629020, 
list_prev = 0xfe00691a5360}, dn_objset = 0xfe00691a5000, dn_object 
= 55652, dn_dbuf = 0xfe00427ad0e0, dn_handle = 0xfe0069f70128, dn_phys 
= 0xff8015eeb800, 
  dn_type = DMU_OT_PLAIN_FILE_CONTENTS, dn_bonuslen = 192, dn_bonustype = 44 
',', dn_nblkptr = 1 '\001', dn_checksum = 0 '\0', dn_compress = 0 '\0', 
dn_nlevels = 1 '\001', dn_indblkshift = 14 '\016', 
  dn_datablkshift = 0 '\0', dn_moved = 0 '\0', dn_datablkszsec = 10, 
dn_datablksz = 5120, dn_maxblkid = 0, dn_next_nblkptr = \000\000\000, 
dn_next_nlevels = \000\000\000, 
  dn_next_indblkshift = \000\000\000, dn_next_bonustype = ,\000\000, 
dn_rm_spillblk = \000\000\000, dn_next_bonuslen = {192, 0, 0, 0}, 
dn_next_blksz = {0, 0, 0, 0}, dn_dbufs_count = 0, dn_dirty_link = {{
  list_next = 0xfe00691a51f0, list_prev = 0xfe0042628ab0}, 
{list_next = 0x0, list_prev = 0x0}, {list_next = 0x0, list_prev = 0x0}, 
{list_next = 0x0, list_prev = 0x0}}, dn_mtx = {lock_object = {
  lo_name = 

Re: panic: solaris assert: sa.sa_magic == 0x2F505A (0x4d5ea364 == 0x2f505a), file: /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c, line: 625

[Fabian Keil]

Andriy Gapon a...@freebsd.org wrote:

 on 01/04/2013 17:18 Fabian Keil said the following:
  #10 0x8130323f in assfail3 (a=value optimized out, lv=value 
  optimized out, op=value optimized out, rv=value optimized out, 
  f=value optimized out, l=value optimized out)
  at 
  /usr/src/sys/modules/opensolaris/../../cddl/compat/opensolaris/kern/opensolaris_cmn_err.c:89
  #11 0x8117924e in zfs_space_delta_cb (bonustype=value optimized 
  out, data=0xff8015eeb8c0, userp=0xfe004261c640, 
  groupp=0xfe004261c648)
  at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c:625
  #12 0x8110003b in dmu_objset_userquota_get_ids 
  (dn=0xfe004261c358, before=0, tx=value optimized out) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:1249
  #13 0x811071b6 in dnode_sync (dn=0xfe004261c358, 
  tx=0xfe00186e1300) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dnode_sync.c:554
  #14 0x810ff98b in dmu_objset_sync_dnodes (list=0xfe00691a5250, 
  newlist=value optimized out, tx=value optimized out)
  at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:910
  #15 0x810ff825 in dmu_objset_sync (os=0xfe00691a5000, 
  pio=value optimized out, tx=0xfe00186e1300)
  at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:1027
  #16 0x8110cb0d in dsl_dataset_sync (ds=0xfe001f3d0c00, 
  zio=0x780, tx=0xfe00186e1300) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dsl_dataset.c:1411
  #17 0x8111399a in dsl_pool_sync (dp=0xfe0069ec4000, txg=value 
  optimized out) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dsl_pool.c:409
  #18 0x8112f0ee in spa_sync (spa=0xfe0050f0, txg=3292) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/spa.c:6328
  #19 0x81137c45 in txg_sync_thread (arg=0xfe0069ec4000) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/txg.c:493
  #20 0x80569c1a in fork_exit (callout=0x811378d0 
  txg_sync_thread, arg=0xfe0069ec4000, frame=0xff80dc9d6c00) at 
  /usr/src/sys/kern/kern_fork.c:991
  #21 0x8086a1ee in fork_trampoline () at exception.S:602
  #22 0x in ?? ()
  Current language:  auto; currently minimal
  (kgdb) f 12
  #12 0x8110003b in dmu_objset_userquota_get_ids 
  (dn=0xfe004261c358, before=0, tx=value optimized out) at 
  /usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/dmu_objset.c:1249
  1249error = 
  used_cbs[os-os_phys-os_type](dn-dn_bonustype, data,
  (kgdb) p *dn
 
 Could you please also provide *dn-dn_phys?

vmcore.12:

(kgdb)  p *dn-dn_phys
Cannot access memory at address 0xff8019492800
(kgdb)  p *dn-dn_dbuf
$1 = {db = {db_object = 0, db_offset = 28491776, db_size = 16384, db_data = 
0xff8019492000}, db_objset = 0xfe002bc62400, db_dnode_handle = 
0xfe002bc62420, db_parent = 0xfe005f1071c0, 
  db_hash_next = 0x0, db_blkid = 1739, db_blkptr = 0xff801936c580, db_level 
= 0 '\0', db_mtx = {lock_object = {lo_name = 0x811d8696 db-db_mtx, 
lo_flags = 4096, lo_data = 0, 
  lo_witness = 0x0}, sx_lock = 1}, db_state = DB_CACHED, db_holds = 
{rc_count = 2}, db_buf = 0xfe005f34c798, db_changed = {cv_description = 
0x811d86a2 db-db_changed, cv_waiters = 0}, 
  db_data_pending = 0xfe004bcc0c00, db_last_dirty = 0xfe004bcc0c00, 
db_link = {list_next = 0xfe005f3506d0, list_prev = 0xfe0030c392a0}, 
db_user_ptr = 0xfe005f269000, 
  db_user_data_ptr_ptr = 0x0, db_evict_func = 0x81105770 
dnode_buf_pageout, db_immediate_evict = 0 '\0', db_freed_in_flight = 0 '\0', 
db_dirtycnt = 1 '\001'}

vmcore.13:

(kgdb)  p *dn-dn_phys
Cannot access memory at address 0xff8015eeb800
(kgdb) p *dn-dn_dbuf
$1 = {db = {db_object = 0, db_offset = 28491776, db_size = 16384, db_data = 
0xff8015eeb000}, db_objset = 0xfe00691a5000, db_dnode_handle = 
0xfe00691a5020, db_parent = 0xfe004254ab60, 
  db_hash_next = 0x0, db_blkid = 1739, db_blkptr = 0xff8015d65580, db_level 
= 0 '\0', db_mtx = {lock_object = {lo_name = 0x811d8696 db-db_mtx, 
lo_flags = 4096, lo_data = 0, 
  lo_witness = 0x0}, sx_lock = 1}, db_state = DB_CACHED, db_holds = 
{rc_count = 2}, db_buf = 0xfe0042bedcf0, db_changed = {cv_description = 
0x811d86a2 db-db_changed, cv_waiters = 0}, 
  db_data_pending = 0xfe00406d6500, db_last_dirty = 0xfe00406d6500, 
db_link = {list_next = 0xfe0042758c10, list_prev = 0xfe0069cab5f8}, 
db_user_ptr = 0xfe0069f7, 
  db_user_data_ptr_ptr = 0x0, db_evict_func = 0x81105770 
dnode_buf_pageout, db_immediate_evict = 0 '\0

Re: geli(8) breaks after a couple hours of uptime

[Fabian Keil]

Pawel Jakub Dawidek p...@freebsd.org wrote:

 On Sun, Feb 10, 2013 at 09:50:58AM +0200, Andriy Gapon wrote:
 
  I think that PAGE_SIZE (or at most a small multiple of it) should be
  sufficient. I don't think that we currently have (or expect to see in
  the near future) algorithms where keys with more than 4096 size
  provide any additional security.
 
 geli(8) deals just fine with files that are larger than buffers, so even
 with smaller buffer it can read the data in few steps.
 
 The proposed patch is here if someone would like to give it a try:
 
   http://people.freebsd.org/~pjd/patches/geom_eli.c.patch

Works for me, thanks a lot.

I tested with a couple of geli providers ranging from
v3 AES-CBC 128 bit to v7 AES-XTS 256 bit and didn't get
any crashes.

Fabian


signature.asc
Description: PGP signature

Re: 7+ days of dogfood

[Fabian Keil]

Steve Kargl s...@troutmask.apl.washington.edu wrote:

 In a long thread started by Peter Wemm on developers@, he described
 the move/upgrade of the FreeBSD.org cluster to using FreeBSD-10.  A
 part of his description included the need to test top-of-tree under
 actual real-world conditions.  In his words, FreeBSD should eat its
 own dogfood.  The new installation on FreeBSD.org, of course, would
 test FreeBSD-10 under (heavy) server load. 

Sounds like an interesting thread, too bad that it happened
behind closed doors.
 
 Unfortunately, trying to build firefox with debugging leads
 reveals a broken port and building chrome with debugging leads
 to a file system full issue (because it is a laptop with only
 limited disk space).

I usually build everything (except the known-to-be-broken png)
with debugging and while Firefox indeed seems to crash even
more often than usual the port isn't completely broken for me.
I disable some of the more crash-prone options, though.
The remaining crashes mostly happen upon exit so they are easy
to ignore.

While I have the space to save the core dumps my system is too
slow to conveniently look at them with gdb and I have given up
on Firefox anyway. I intend to deflect to chromium once I find
a more powerful replacement for my current (pun intended) laptop.

 My conclusion:  on at least my not-so-new laptop, FreeBSD-10 can
 be used in a desktop environment if one takes some care during the
 installation.

I'm using CURRENT on my also-no-so-new laptop since FreeBSD 7
(I think) and came to the same conclusion.

It's unfortunate that the builworld time roughly trippled since
2010 but I guess that's progress and a more powerful system
should fix it. I certainly welcome clang in general, though.

Fabian


signature.asc
Description: PGP signature

Re: 7+ days of dogfood

[Fabian Keil]

Erich Dollansky erichsfreebsdl...@alogt.com wrote:

 On Mon, 11 Feb 2013 11:48:11 +0100
 Fabian Keil freebsd-lis...@fabiankeil.de wrote:

  It's unfortunate that the builworld time roughly trippled since
  2010 but I guess that's progress and a more powerful system
  should fix it. I certainly welcome clang in general, though.
  
 Trippled? Are you sure? I have the feeling it is much worse than this.

I'm sure it depends on lots of factors and our worlds probably
don't even match.

I intend to eventually plot the numbers I've collected over the years
(mainly to have a baseline for ZFS tuning) but so far I haven't and
just looked at the first and last ones:

--
 Kernel build for ZOEY completed on Mon May 31 17:18:12 CEST 2010
--

real10m42.935s
user8m16.834s
sys 1m22.951s
--
 World build completed on Mon May 31 18:38:59 CEST 2010
--

real71m16.524s
user51m55.771s
sys 12m24.944s

# FreeBSD r500.local 10.0-CURRENT FreeBSD 10.0-CURRENT #543 r+b74c91e: Sun Feb  
3 17:17:03 CET 2013 fk@r500.local:/usr/obj/usr/src/sys/ZOEY  amd64
--
 World build completed on Tue Feb  5 21:33:55 CET 2013
--

real261m25.904s
user189m2.690s
sys 22m46.777s

# FreeBSD r500.local 10.0-CURRENT FreeBSD 10.0-CURRENT #547 r+21d959a: Sun Feb 
10 16:00:14 CET 2013 fk@r500.local:/usr/obj/usr/src/sys/ZOEY  amd64
--
 Kernel build for ZOEY completed on Sun Feb 10 21:41:31 CET 2013
--

real18m34.822s
user12m13.900s
sys 2m14.028s

fk@r500 ~ $expr 261 / 71
3

I agree that it feels worse, though.

Disclaimer: These aren't benchmark results, I didn't create them in
single-user mode and various relevant factors vary. I also didn't run
the numbers through ministat and don't intend to either.

 Was it in 2009 when I could compile world in a few minutes on my quad
 core. The same machine takes now hours despite having more memory.

I'm using a Core(TM)2 Duo CPU T5870 @ 2.00GHz and don't remember
ever being able to compile world in a few minutes. The bottle
neck on my system seems to be the puny 2 GB of RAM the linker
has to share with ZFS.

At least I can still buildworld without first attaching an USB
stick for additional swap space which is necessary for Firefox ...

Fabian


signature.asc
Description: PGP signature

Re: 7+ days of dogfood

[Fabian Keil]

David Chisnall thera...@freebsd.org wrote:

 On 11 Feb 2013, at 10:48, Fabian Keil freebsd-lis...@fabiankeil.de
 wrote:
 
  It's unfortunate that the builworld time roughly trippled since
  2010 but I guess that's progress and a more powerful system
  should fix it. I certainly welcome clang in general, though.
 
 In that case, it's worth noting that you can shave a fair bit off the
 build time by not building gcc.

Those gcc bits are shaved off already, that's why the buildworld
finishes so quickly now ...

My last result with both clang and gcc seems to be:

--
 World build completed on Mon Dec 24 22:55:21 CET 2012
--

real350m42.363s
user253m5.477s
sys 50m0.024s


  WITHOUT_GCC=yes in src.conf is
 worthwhile.  WITHOUT_GDB=yes is probably also sensible, as the gdb in
 base is so old that it doesn't understand most of the DWARF that clang
 uses.  We should have lldb ready for import in a few months, but until
 then using gdb from ports is more sensible if you plan on actually doing
 any debugging.

So far I didn't consider not building gdb, but I agree that it's
not too useful when compiling with clang and am already using
gdb751 for debugging anyway.

My impression was that the base gdb compiles rather quickly
(compared to more recent versions) and that it thus wouldn't
matter, but I'll give it a try.

Thanks for the suggestion.

Fabian


signature.asc
Description: PGP signature

Re: 7+ days of dogfood

[Fabian Keil]

David Chisnall david.chisn...@cl.cam.ac.uk wrote:

 On 11 Feb 2013, at 13:56, Fabian Keil freebsd-lis...@fabiankeil.de
 wrote:
 
  real350m42.363s
  user253m5.477s
  sys 50m0.024s
 
 These numbers look a bit wrong.  You've got 300 minutes of CPU time, but
 350 minutes of real time.  In an ideal world, on your dual-core system
 you'd see 150 minutes of real time.  Seeing more than 300 implies that
 you're spending a lot of time waiting for I/O.  The normal
 recommendation is to use -j x where x is 1.5 times the number of cores,
 or 1x the number of GBs of RAM, whichever is smaller.  With only 2GB of
 RAM you might have linking problems with -j3, but it's still worth
 trying.

With only 2 GB of RAM (parts of which are needed elsewhere) I'm already
having linking problems without using -j at all and the I/O I'm waiting
for is the disk serving the swap partition.

I've used -j2 and occasionally -j4 when building world with gcc in
the past, but when using clang I'd risk temporarily having three
(or more) processes compete for swap space and bandwidth, so I
stopped doing that.

I'd expect that another 2 GB of RAM would prevent the swapping and
thus reduce the buildworld time quite a bit, but as I intend to
replace the system anyway I can't be bothered to investigate what
kind of RAM I'd need and where to get it.

 One of the more serious problems with our current build system is that
 it doesn't scale well to large numbers of cores.  On a 32-core system,
 with -j64, we're very rarely managing to have even 8 things able to run
 in parallel.  This should be addressed when the bmake import is fully
 integrated and we can use meta mode for better dependency tracking.  

 Ninja has a concept of pools, so you can say 'only run one link job at a
 time, but you can do two C++ compile jobs or 4 C compile jobs', and it
 might be interesting to look at adding something similar to bmake, as
 this can improve scalability a lot.

Unfortunately I don't have these issues (yet).

Fabian


signature.asc
Description: PGP signature

Re: 7+ days of dogfood

[Fabian Keil]

Glen Barber g...@freebsd.org wrote:

 On Mon, Feb 11, 2013 at 02:56:47PM +0100, Fabian Keil wrote:
WITHOUT_GCC=yes in src.conf is
   worthwhile.  WITHOUT_GDB=yes is probably also sensible, as the gdb in
   base is so old that it doesn't understand most of the DWARF that
   clang uses.  We should have lldb ready for import in a few months,
   but until then using gdb from ports is more sensible if you plan on
   actually doing any debugging.
  
  So far I didn't consider not building gdb, but I agree that it's
  not too useful when compiling with clang and am already using
  gdb751 for debugging anyway.
  
  My impression was that the base gdb compiles rather quickly
  (compared to more recent versions) and that it thus wouldn't
  matter, but I'll give it a try.
  
  Thanks for the suggestion.
  
 
 You might also want to try MALLOC_PRODUCTION=1 in make.conf.  This took
 my buildworld/buildkernel times from 35/15 minutes to 8/5 minutes,
 respectively.

I've been using MALLOC_PRODUCTION since before I started collecting
build times and don't remember the impact, but I think the difference
was less impressive than in your case and the massive slowdowns that
are now supposed to be fixed only happened recently (after 2010)
and thus never affected me. Thanks, though.

Fabian


signature.asc
Description: PGP signature

Re: geli(8) breaks after a couple hours of uptime

[Fabian Keil]

Eitan Adler li...@eitanadler.com wrote:

 On 8 February 2013 07:46, Andriy Gapon a...@freebsd.org wrote:
  on 08/02/2013 13:48 Ulrich Spörlein said the following:

  It looks like 128k as a limit is still too low for geli(8) to work, and
  I've set it to 256k now, so that I can use sudo geli. Can you maybe
  revise the patch to not use 1024k as an arbitrary limit, but rather make
  sure you test for precisely as much memory as will be needed?

IIRC 256K didn't work for me, 512K did, so I doubled it
to have some leg room.

I'm not sure it's possible to reliably estimate the required
memory without first changing geli to mlock less generously,
something Konstantin suggested in:
http://lists.freebsd.org/pipermail/svn-src-all/2013-January/063939.html

While I agree that mlocking less generously would technically be a
better solution than increasing the limit, it would also require a lot
more work, additional audits to make sure it's done correctly and in
case of geli I don't really see a problem with mlocking 1024K for a
few seconds.

  Also, can we maybe revisit the new 64k default limit, as it will
  obviously make peoples work with geli a bit painful, this should work
  out of the box.
 
  I have some, IMO, better suggestions:
  - use -c option with sudo

I usually execute sudo geli through a wrapper (zogftw) so this
makes patching geli optional for me. Thanks for mentioning it (again).

  - tune your system for your needs
 
  - [major] abolish the silliness of tying resource limits to login class and 
  apply
  resource limits based on user and group IDs; including after su/sudo 
  (subject to
  local policies)

While we are dreaming, it would be nice to have more resource limits
that apply to all the processes belonging to the user combined.

It also wouldn't hurt to document why a 64K per-process limit with an
unlimited number of processes per user is considered a good default in
the first place.

 The default settings should not make another feature unusable.  At a
 minimum it should be documented in geli's man page that such tuning is
 required.

If the consensus is that 1024K are too much for geli and nobody can
be bothered to come up with a more fine grained mlocking patch,
geli could be changed to check the mlock limit and exit with a
useful error message if it's too low.

This would at least prevent the segfault.

Fabian


signature.asc
Description: PGP signature

Re: Physbio changes final call for tests and reviews

[Fabian Keil]

Konstantin Belousov kostik...@gmail.com wrote:

 I finished the last (insignificant) missed bits in the Jeff' physbio
 work. Now I am asking for the last round of testing and review, esp. for
 the !x86 architectures. Another testing focus are the SCSI HBAs and RAID
 controllers which drivers are changed by the patchset. Please do test
 this before the patchset is committed into HEAD !

I could only test on amd64 without fancy SCSI controllers,
but it works for me.

Fabian


signature.asc
Description: PGP signature

Destroying ZFS snapshots too quickly: xpt_scan_lun: can't allocate CCB, can't continue

[Fabian Keil]

Before the introduction of async_destroy I wrote a script to destroy
ZFS snapshots in parallel to speed up the process. It's available at:
http://www.fabiankeil.de/sourcecode/zfs-snapshot-destroyer/zsd.pl

A couple of years ago the only downside seemed to be that it
requires more memory and file descriptors (due to multiple zfs
processes running at the same time) and that errors are ignored
(implementation detail of the script).

Recently I noticed that destroying several hundred (500)
snapshots this way risks rendering the system unresponsive.
I rarely do that, so it might not actually be a regression.

When using X the screen freezes and keyboard input is ignored
so it's hard to tell what's going on.

When running the script on the console alt+Fx are often still
accepted to switch consoles, but other keyboard input like
entering commands or trying to login has no visible effect.

A running top is killed and the system frequently logs:
xpt_scan_lun: can't allocate CCB, can't continue.

Plugging in USB devices still result in the expected messages,
but other than this the system seems to be unresponsive and
doesn't recover (I only waited a couple of minutes, though).

A CCB seems to be rather small:
http://fxr.watson.org/fxr/source/cam/cam_xpt.c#L4386
therefore I suspect that ZFS got greedy and didn't play nice
with the rest of the system. I have no proof that ZFS isn't
merely triggering a problem in another subsystem, though.

So far I haven't been able to reproduce the problem with snapshots
intentionally created for testing, but I also used a somewhat
simplistic approach to populate the snapshots.

Is this considered a bug or is quickly destroying snapshots just
something for the don't do this or not without proper tuning
departments?

I would also be interested to know if there's a way to somehow
roughly figure out from userland how many snapshots can be safely
destroyed in a row. Example: Look at some system state, destroy
a safe amount of snapshots, look at some system state again and
interpolate.

Before top gets killed it usually shows that zfskern takes
more than 50% WCPU, but this can also happen when the system
doesn't become unresponsive and thus probably isn't a good
metric (the delay also doesn't help of course).

Fabian


signature.asc
Description: PGP signature

Re: geli(8) breaks after a couple hours of uptime

[Fabian Keil]

Ulrich Spörlein u...@freebsd.org wrote:

 On Thu, 2013-02-07 at 15:33:22 +0100, Fabian Keil wrote:
  Ulrich Spörlein u...@freebsd.org wrote:
  
   Yes, it's pretty much as weird as it sounds. All new machine, forklifted
   the image from on old i386 machine running 8.x to current on amd64.
   
   Everything seemingly works fine, attaching geli volumes shortly after
   boot is fine, attached devices continue to work fine. There are no
   strange crashes with this machine or anything, but when I try to attach
   an USB volume the next day, geli attach segfaults.
  
  This could be:
  http://www.freebsd.org/cgi/query-pr.cgi?pr=174831

 Except it happens to me when run as root, and:

Depending on your settings the limit could still apply.
Did you check with ulimit -l to be sure?

 root@coyote:~# sysctl vm.old_mlock
 vm.old_mlock: 0

Looks like I got the logic wrong in the PR ...

fk@r500 ~ $sysctl -d vm.old_mlock
vm.old_mlock: Do not apply RLIMIT_MEMLOCK on mlockall

Fabian


signature.asc
Description: PGP signature

Re: geli(8) breaks after a couple hours of uptime

[Fabian Keil]

Ulrich Spörlein u...@freebsd.org wrote:

 Yes, it's pretty much as weird as it sounds. All new machine, forklifted
 the image from on old i386 machine running 8.x to current on amd64.
 
 Everything seemingly works fine, attaching geli volumes shortly after
 boot is fine, attached devices continue to work fine. There are no
 strange crashes with this machine or anything, but when I try to attach
 an USB volume the next day, geli attach segfaults.

This could be:
http://www.freebsd.org/cgi/query-pr.cgi?pr=174831

Fabian


signature.asc
Description: PGP signature

Re: Zpool surgery

[Fabian Keil]

Dan Nelson dnel...@allantgroup.com wrote:

 In the last episode (Jan 28), Fabian Keil said:
  Ulrich Spörlein u...@freebsd.org wrote:
   On Mon, 2013-01-28 at 07:11:40 +1100, Peter Jeremy wrote:
On 2013-Jan-27 14:31:56 -, Steven Hartland 
kill...@multiplay.co.uk wrote:
- Original Message - 
From: Ulrich Spörlein u...@freebsd.org
 I want to transplant my old zpool tank from a 1TB drive to a new
 2TB drive, but *not* use dd(1) or any other cloning mechanism, as
 the pool was very full very often and is surely severely
 fragmented.

Cant you just drop the disk in the original machine, set it as a
mirror then once the mirror process has completed break the mirror
and remove the 1TB disk.

That will replicate any fragmentation as well.  zfs send | zfs recv
is the only (current) way to defragment a ZFS pool.
  
  It's not obvious to me why zpool replace (or doing it manually)
  would replicate the fragmentation.
 
 zpool replace essentially adds your new disk as a mirror to the parent
 vdev, then deletes the original disk when the resilver is done.  Since
 mirrors are block-identical copies of each other, the new disk will contain
 an exact copy of the original disk, followed by 1TB of freespace.

Thanks for the explanation.

I was under the impression that zfs mirrors worked at a higher
level than traditional mirrors like gmirror but there seems to
be indeed less magic than I expected.

Fabian


signature.asc
Description: PGP signature

Re: Zpool surgery

[Fabian Keil]

Ulrich Spörlein u...@freebsd.org wrote:

 On Mon, 2013-01-28 at 07:11:40 +1100, Peter Jeremy wrote:
  On 2013-Jan-27 14:31:56 -, Steven Hartland kill...@multiplay.co.uk 
  wrote:
  - Original Message - 
  From: Ulrich Spörlein u...@freebsd.org
   I want to transplant my old zpool tank from a 1TB drive to a new 2TB
   drive, but *not* use dd(1) or any other cloning mechanism, as the pool
   was very full very often and is surely severely fragmented.
  
  Cant you just drop the disk in the original machine, set it as a mirror
  then once the mirror process has completed break the mirror and remove
  the 1TB disk.
  
  That will replicate any fragmentation as well.  zfs send | zfs recv
  is the only (current) way to defragment a ZFS pool.

It's not obvious to me why zpool replace (or doing it manually)
would replicate the fragmentation.

 But are you then also supposed to be able send incremental snapshots to
 a third pool from the pool that you just cloned?

Yes.

 I did the zpool replace now over night, and it did not remove the old
 device yet, as it found cksum errors on the pool:
 
 root@coyote:~# zpool status -v
   pool: tank
  state: ONLINE
 status: One or more devices has experienced an error resulting in data
 corruption.  Applications may be affected.
 action: Restore the file in question if possible.  Otherwise restore the
 entire pool from backup.
see: http://illumos.org/msg/ZFS-8000-8A
   scan: resilvered 873G in 11h33m with 24 errors on Mon Jan 28 09:45:32 2013
 config:
 
 NAME   STATE READ WRITE CKSUM
 tank   ONLINE   0 027
   replacing-0  ONLINE   0 061
 da0.eliONLINE   0 061
 ada1.eli   ONLINE   0 061
 
 errors: Permanent errors have been detected in the following files:
 
 
 tank/src@2013-01-17:/.svn/pristine/8e/8ed35772a38e0fec00bc1cbc2f05480f4fd4759b.svn-base
[...]
 tank/ncvs@2013-01-17:/ports/textproc/uncrustify/distinfo,v
 
 Interestingly, these only seem to affect the snapshot, and I'm now
 wondering if that is the problem why the backup pool did not accept the
 next incremental snapshot from the new pool.

I doubt that. My expectation would be that it only prevents
the zfs send to finish successfully.

BTW, you could try reading the files to be sure that the checksum
problems are permanent and not just temporary USB issues.

 How does the receiving pool known that it has the correct snapshot to
 store an incremental one anyway? Is there a toplevel checksum, like for
 git commits? How can I display and compare that?

Try zstreamdump:

fk@r500 ~ $sudo zfs send -i @2013-01-24_20:48 tank/etc@2013-01-26_21:14 | 
zstreamdump | head -11
BEGIN record
hdrtype = 1
features = 4
magic = 2f5bacbac
creation_time = 5104392a
type = 2
flags = 0x0
toguid = a1eb3cfe794e675c
fromguid = 77fb8881b19cb41f
toname = tank/etc@2013-01-26_21:14
END checksum = 1047a3f2dceb/67c999f5e40ecf9/442237514c1120ed/efd508ab5203c91c

fk@r500 ~ $sudo zfs send lexmark/backup/r500/tank/etc@2013-01-24_20:48 | 
zstreamdump | head -11
BEGIN record
hdrtype = 1
features = 4
magic = 2f5bacbac
creation_time = 51018ff4
type = 2
flags = 0x0
toguid = 77fb8881b19cb41f
fromguid = 0
toname = lexmark/backup/r500/tank/etc@2013-01-24_20:48
END checksum = 1c262b5ffe935/78d8a68e0eb0c8e7/eb1dde3bd923d153/9e0829103649ae22

Fabian


signature.asc
Description: PGP signature

Re: Zpool surgery

[Fabian Keil]

Ulrich Spörlein u...@freebsd.org wrote:

 I have a slight problem with transplanting a zpool, maybe this is not
 possible the way I like to do it, maybe I need to fuzz some
 identifiers...
 
 I want to transplant my old zpool tank from a 1TB drive to a new 2TB
 drive, but *not* use dd(1) or any other cloning mechanism, as the pool
 was very full very often and is surely severely fragmented.
 
 So, I have tank (the old one), the new one, let's call it tank' and
 then there's the archive pool where snapshots from tank are sent to, and
 these should now come from tank' in the future.
 
 I have:
 tank - sending snapshots to archive
 
 I want:
 tank' - sending snapshots to archive
 
 Ideally I would want archive to not even know that tank and tank' are
 different, so as to not have to send a full snapshot again, but
 continue the incremental snapshots.
 
 So I did zfs send -R tank | ssh otherhost zfs recv -d tank and that
 worked well, this contained a snapshot A that was also already on
 archive. Then I made a final snapshot B on tank, before turning down that
 pool and sent it to tank' as well.
 
 Now I have snapshot A on tank, tank' and archive and they are virtually
 identical. I have snapshot B on tank and tank' and would like to send
 this from tank' to archive, but it complains:
 
 cannot receive incremental stream: most recent snapshot of archive does
 not match incremental source

In general this should work, so I'd suggest that you double check
that you are indeed sending the correct incremental.

 Is there a way to tweak the identity of tank' to be *really* the same as
 tank, so that archive can accept that incremental stream? Or should I
 use dd(1) after all to transplant tank to tank'? My other option would
 be to turn on dedup on archive and send another full stream of tank',
 99.9% of which would hopefully be deduped and not consume precious space
 on archive.

The pools don't have to be the same.

I wouldn't consider dedup as you'll have to recreate the pool if
it turns out the the dedup performance is pathetic. On a system
that hasn't been created with dedup in mind that seems rather
likely.

 Any ideas?

Your whole procedure seems a bit complicated to me.

Why don't you use zpool replace?

Fabian


signature.asc
Description: PGP signature

Re: disk flipped - a known problem?

[Fabian Keil]

Andriy Gapon a...@freebsd.org wrote:

 Today something unusual happened on one of my machines:
 kernel: (ada0:ahcich0:0:0:0): lost device
 kernel: (aprobe1:ahcich0:0:15:0): NOP. ACB: 00 00 00 00 00 00 00 00 00 00 00 
 00
 kernel: (aprobe1:ahcich0:0:15:0): CAM status: Command timeout
 kernel: (aprobe1:ahcich0:0:15:0): Error 5, Retries exhausted
 kernel: (aprobe1:ahcich0:0:15:0): NOP. ACB: 00 00 00 00 00 00 00 00 00 00 00 
 00
 kernel: (aprobe1:ahcich0:0:15:0): CAM status: Command timeout
 kernel: (aprobe1:ahcich0:0:15:0): Error 5, Retries exhausted
 kernel: cam_periph_alloc: attempt to re-allocate valid device ada0 rejected
 flags 0x18 refcount 1
 kernel: adaasync: Unable to attach to new device due to status 0x6

I believe I saw something similar when trying to forcefully
end the cam lockups reported in:
http://lists.freebsd.org/pipermail/freebsd-current/2012-October/037413.html

Detaching the disc drive caused /dev/cd0 to disappear as expected,
but reinserting the drive didn't bring cd0 back.

 It looks like the disk disappeared from the bus and then re-appeared on the 
 bus,
 but not to the OS.
 
 One of the partitions that the disk hosted was a swap partition and it seems 
 to
 be the cause of some of the following consequences.
 
 The consequences:
[...]
 * geom_event thread started consuming 100% of CPU in g_wither_washer()

This sounds familiar as well:
http://www.freebsd.org/cgi/query-pr.cgi?pr=171865

Fabian


signature.asc
Description: PGP signature

Re: make buildworld failures with NO_KERBEROS=

[Fabian Keil]

Steve Kargl s...@troutmask.apl.washington.edu wrote:

 On Fri, Jan 18, 2013 at 08:54:03PM +0100, Fabian Keil wrote:
  Recently make buildworld started failing for me:
  
  8
  === include/xlocale (installincludes)
  sh /usr/src/tools/install.sh -C -o root -g wheel -m 444  _ctype.h 
  _inttypes.h _langinfo.h _locale.h _monetary.h _stdio.h _stdlib.h _string.h 
  _time.h _wchar.h /usr/obj/usr/src/tmp/usr/include/xlocale
  === kerberos5 (includes)
  set -e; cd /usr/src/kerberos5; /usr/obj/usr/src/make.amd64/make 
  buildincludes; /usr/obj/usr/src/make.amd64/make installincludes
  === kerberos5/doc (buildincludes)
  === kerberos5/lib (buildincludes)
  === kerberos5/lib/libasn1 (buildincludes)
  compile_et 
  /usr/src/kerberos5/lib/libasn1/../../../crypto/heimdal/lib/asn1/asn1_err.et
  compile_et: No such file or directory
  *** [asn1_err.h] Error code 1
  
 
 See the thread started here:
 http://lists.freebsd.org/pipermail/freebsd-current/2013-January/039083.html

Thanks.

Fabian


signature.asc
Description: PGP signature

make buildworld failures with NO_KERBEROS=

[Fabian Keil]

Recently make buildworld started failing for me:

8
=== include/xlocale (installincludes)
sh /usr/src/tools/install.sh -C -o root -g wheel -m 444  _ctype.h _inttypes.h 
_langinfo.h _locale.h _monetary.h _stdio.h _stdlib.h _string.h _time.h _wchar.h 
/usr/obj/usr/src/tmp/usr/include/xlocale
=== kerberos5 (includes)
set -e; cd /usr/src/kerberos5; /usr/obj/usr/src/make.amd64/make buildincludes; 
/usr/obj/usr/src/make.amd64/make installincludes
=== kerberos5/doc (buildincludes)
=== kerberos5/lib (buildincludes)
=== kerberos5/lib/libasn1 (buildincludes)
compile_et 
/usr/src/kerberos5/lib/libasn1/../../../crypto/heimdal/lib/asn1/asn1_err.et
compile_et: No such file or directory
*** [asn1_err.h] Error code 1

Stop in /usr/src/kerberos5/lib/libasn1.
*** [buildincludes] Error code 1

Stop in /usr/src/kerberos5/lib.
*** [buildincludes] Error code 1

Stop in /usr/src/kerberos5.
*** [includes] Error code 1

Stop in /usr/src/kerberos5.
*** [kerberos5.includes__D] Error code 1

Stop in /usr/src.
*** [_includes] Error code 1

Stop in /usr/src.
*** [buildworld] Error code 1

Stop in /usr/src.
8

I was still using the recently de-supported NO_KERBEROS= and
changing it to WITHOUT_KERBEROS= got it working again.

I'm still wondering if this is the expected behaviour, though.

Shouldn't buildworld create a usable compile_et instead of
relying on compile_et's existence in /usr/bin?

Fabian


signature.asc
Description: PGP signature

standards/173421: [patch] strptime() accepts formats that should be rejected

[Fabian Keil]

Anyone interested in a PR for a strptime() bug coming with
a test case and a potential fix?

 http://www.freebsd.org/cgi/query-pr.cgi?pr=173421
 
 Category:   standards
 Responsible:freebsd-standards
 Synopsis:   [patch] strptime() accepts formats that should be rejected
 Arrival-Date:   Tue Nov 06 14:30:00 UTC 2012

Looks like freebsd-standards@ is not the most active mailing list.

Fabian


signature.asc
Description: PGP signature

Re: ZFS/RAIDZ and SAMBA: abyssimal performance

[Fabian Keil]

Garrett Cooper yaneg...@gmail.com wrote:

 On Fri, Jan 4, 2013 at 10:28 AM, Fabian Keil
 freebsd-lis...@fabiankeil.de wrote:

  While I agree that the values are system dependant the purpose of
  the tunables could still be documented together with a description
  of how to properly test that they have any effect at all and that
  it's an improvement compared to the defaults.
 
  Scarce ZFS tuning documentation is also a problem upstream which
  probably doesn't help.
 
 The documentation is there (see the Evil ZFS Tuning Guide, etc), the
 problem is that our OS is Solaris so the directions do not directly
 apply.

I was actually referring to the Evil ZFS Tuning Guide which,
while helpful, doesn't come close to completely documenting the
tunables that exist and in my opinion also doesn't really address
the testing issue.

Obviously I don't expect anyone else to benchmark my own systems for
me, but more information about the expected effects would allow me
to test more efficiently.

The fact that it targets Solaris and that the directions don't
apply directly never bothered me so far and I think the existing
parts are pretty good in general.

Fabian


signature.asc
Description: PGP signature

Re: Unbreaking gdb's catch throw

[Fabian Keil]

Stefan Farfeleder stef...@freebsd.org wrote:

 gdb's command 'catch throw' is broken on FreeBSD head. While it does set
 a breakpoint on __cxa_throw, the function seems to be never entered when
 an exception is thrown. Does someone know how to fix this? It used to
 work a couple of months ago.

My impression is that gdb from base is pretty useless in general
when compiling with a modern compiler like clang or a more recent
version of gcc.

gdb751 from the ports seems to suck a lot less.

Obviously I'm not saying that it wouldn't be nice if gdb
from base worked better, though.

Fabian


signature.asc
Description: PGP signature

Re: ZFS/RAIDZ and SAMBA: abyssimal performance

[Fabian Keil]

Fleuriot Damien m...@my.gd wrote:

 
 On Jan 4, 2013, at 4:19 PM, O. Hartmann ohart...@zedat.fu-berlin.de wrote:
 
  Am 01/04/13 15:45, schrieb Garrett Cooper:
  On Fri, Jan 4, 2013 at 6:06 AM, Fleuriot Damien m...@my.gd wrote:
  
  ...
  
  And this is under [global] in /usr/local/etc/smb.conf:
min receivefile size = 16384
aio read size = 16384
aio write size = 16384
aio write behind = yes
  
  These are still pretty low, depending on what your networking/disk
  setup is like; my important performance settings are:
  
 socket options = SO_RCVBUF=64240 SO_SNDBUF=64240 TCP_NODELAY
  IPTOS_LOWDELAY IPTOS_THROUGHPUT
 write cache size = 65536
 aio read size = 65536
 aio write size = 65536
 directory name cache size = 0

  Well, now I have peak values ~ 120 MB/s when copying. I applied Fleuriot
  Damien's values to /boot/loader.conf and yours to the smb.conf.
  Somewhere in the handbook this should be documented! it is to much
  efford to get SAMBA working properly with ZFS, if the tricks and
  problems are so widespread over several architectural aspects of the system.
  
  It could save a lot of time for adminsitartors and those which try
  FreeBSD as a serving system instead of Linux.
  
  Just for the record. I feel a bit confused about all the tricks and
  tweak now published for ZFS, its magic L2ARC, the kernel_vmem wizzardy
  thingis. The ZFS Wiki seems to be a bit outdated and confusing, it would
  be a great deal if all these things could be lined up a s a primer with
  a bit more explanations than put this number there.

 The problem, Oliver, is that these values are system dependant.

While I agree that the values are system dependant the purpose of
the tunables could still be documented together with a description
of how to properly test that they have any effect at all and that
it's an improvement compared to the defaults.

Scarce ZFS tuning documentation is also a problem upstream which
probably doesn't help.

Fabian


signature.asc
Description: PGP signature

Re: [RFC/RFT] calloutng

[Fabian Keil]

Fabian Keil freebsd-lis...@fabiankeil.de wrote:

 Alexander Motin m...@freebsd.org wrote:
 
  On 20.12.2012 15:26, Fabian Keil wrote:
   Alexander Motin m...@freebsd.org wrote:
  
   On 20.12.2012 12:56, Fabian Keil wrote:
   Alexander Motin m...@freebsd.org wrote:
  
   Experiments with dummynet shown ineffective support for very short
   tick-based callouts. New version fixes that, allowing to get as many
   tick-based callout events as hz value permits, while still be able to
   aggregate events and generating minimum of interrupts.
  
   Also this version modifies system load average calculation to fix some
   cases existing in HEAD and 9 branches, that could be fixed with new
   direct callout functionality.
  
   http://people.freebsd.org/~mav/calloutng_12_17.patch
  
   With this patch (and the previous one, I didn't test the others)
   my mouse cursor is occasionally not reacting for short amounts of
   time (less than a second, but long enough to be noticeable).
 
   Could you try to revert part of the patch, related to dev/atkbdc? I am
   not strong in details of that hardware, but in comments there mention
   that they are related. May be lost keyboard interrupts (which polling
   rate was increased to 1 second) cause PS/2 mouse delays.
  
   I reverted the changes to sys/dev/atkbdc/* about an hour ago
   and so far it's looking good. I'll report back tomorrow after
   some more testing.

Still looking good.

Fabian


signature.asc
Description: PGP signature

Re: [RFC/RFT] calloutng

[Fabian Keil]

Alexander Motin m...@freebsd.org wrote:

 Experiments with dummynet shown ineffective support for very short 
 tick-based callouts. New version fixes that, allowing to get as many 
 tick-based callout events as hz value permits, while still be able to 
 aggregate events and generating minimum of interrupts.
 
 Also this version modifies system load average calculation to fix some 
 cases existing in HEAD and 9 branches, that could be fixed with new 
 direct callout functionality.
 
 http://people.freebsd.org/~mav/calloutng_12_17.patch

With this patch (and the previous one, I didn't test the others)
my mouse cursor is occasionally not reacting for short amounts of
time (less than a second, but long enough to be noticeable).

Every now and then the window manager (i3-wm) changes window focus
which could be explained by either phantom keyboard or mouse input,
or terminal lines are marked as if the cursor was moved with the
left button pressed.

The problems happen a couple of times per hour but I haven't
been able to intentionally reproduce them. They only seem to
occur while I'm moving the cursor, but of course I wouldn't
otherwise notice a unresponsive cursor anyway.

While the cursor is unresponsive, keyboard input and the rest
of the system works as expected as far as I can tell.

If I set debug.psm.loglevel=4 I get a psm0: lost interrupt?
message once per second when not moving the mouse, however that
also happens without the patch and thus might be unrelated.

I'm using moused.

I'm not sure what additional information is necessary to debug this,
so here a bunch of sysctl values that may or may not be relevant:

fk@r500 ~ $sysctl kern.eventtimer kern.timecounter
kern.eventtimer.et.i8254.flags: 1
kern.eventtimer.et.i8254.frequency: 1193182
kern.eventtimer.et.i8254.quality: 100
kern.eventtimer.et.HPET.flags: 3
kern.eventtimer.et.HPET.frequency: 14318180
kern.eventtimer.et.HPET.quality: 450
kern.eventtimer.et.HPET1.flags: 3
kern.eventtimer.et.HPET1.frequency: 14318180
kern.eventtimer.et.HPET1.quality: 440
kern.eventtimer.et.HPET2.flags: 3
kern.eventtimer.et.HPET2.frequency: 14318180
kern.eventtimer.et.HPET2.quality: 440
kern.eventtimer.et.HPET3.flags: 3
kern.eventtimer.et.HPET3.frequency: 14318180
kern.eventtimer.et.HPET3.quality: 440
kern.eventtimer.choice: HPET(450) HPET1(440) HPET2(440) HPET3(440) i8254(100)
kern.eventtimer.singlemul: 2
kern.eventtimer.idletick: 0
kern.eventtimer.activetick: 1
kern.eventtimer.timer: HPET
kern.eventtimer.periodic: 0
kern.timecounter.tc.i8254.mask: 65535
kern.timecounter.tc.i8254.counter: 25970
kern.timecounter.tc.i8254.frequency: 1193182
kern.timecounter.tc.i8254.quality: 0
kern.timecounter.tc.HPET.mask: 4294967295
kern.timecounter.tc.HPET.counter: 3963519587
kern.timecounter.tc.HPET.frequency: 14318180
kern.timecounter.tc.HPET.quality: 950
kern.timecounter.tc.ACPI-fast.mask: 16777215
kern.timecounter.tc.ACPI-fast.counter: 7323739
kern.timecounter.tc.ACPI-fast.frequency: 3579545
kern.timecounter.tc.ACPI-fast.quality: 900
kern.timecounter.tc.TSC.mask: 4294967295
kern.timecounter.tc.TSC.counter: 454465294
kern.timecounter.tc.TSC.frequency: 1995040520
kern.timecounter.tc.TSC.quality: -1000
kern.timecounter.stepwarnings: 0
kern.timecounter.hardware: HPET
kern.timecounter.choice: TSC(-1000) ACPI-fast(900) HPET(950) i8254(0) 
dummy(-100)
kern.timecounter.tick: 1
kern.timecounter.fast_gettime: 1
kern.timecounter.invariant_tsc: 1
kern.timecounter.smp_tsc: 0

The system is a Lenovo R500 with a
Intel(R) Core(TM)2 Duo CPU T5870  @ 2.00GHz (1995.04-MHz K8-class CPU)

Fabian


signature.asc
Description: PGP signature

Re: [RFC/RFT] calloutng

[Fabian Keil]

Alexander Motin m...@freebsd.org wrote:

 On 20.12.2012 12:56, Fabian Keil wrote:
  Alexander Motin m...@freebsd.org wrote:
 
  Experiments with dummynet shown ineffective support for very short
  tick-based callouts. New version fixes that, allowing to get as many
  tick-based callout events as hz value permits, while still be able to
  aggregate events and generating minimum of interrupts.
 
  Also this version modifies system load average calculation to fix some
  cases existing in HEAD and 9 branches, that could be fixed with new
  direct callout functionality.
 
  http://people.freebsd.org/~mav/calloutng_12_17.patch
 
  With this patch (and the previous one, I didn't test the others)
  my mouse cursor is occasionally not reacting for short amounts of
  time (less than a second, but long enough to be noticeable).
 
  Every now and then the window manager (i3-wm) changes window focus
  which could be explained by either phantom keyboard or mouse input,
  or terminal lines are marked as if the cursor was moved with the
  left button pressed.
 
  The problems happen a couple of times per hour but I haven't
  been able to intentionally reproduce them. They only seem to
  occur while I'm moving the cursor, but of course I wouldn't
  otherwise notice a unresponsive cursor anyway.
 
  While the cursor is unresponsive, keyboard input and the rest
  of the system works as expected as far as I can tell.
 
  If I set debug.psm.loglevel=4 I get a psm0: lost interrupt?
  message once per second when not moving the mouse, however that
  also happens without the patch and thus might be unrelated.
 
  I'm using moused.
 
 Could you try to revert part of the patch, related to dev/atkbdc? I am 
 not strong in details of that hardware, but in comments there mention 
 that they are related. May be lost keyboard interrupts (which polling 
 rate was increased to 1 second) cause PS/2 mouse delays.
 
I reverted the changes to sys/dev/atkbdc/* about an hour ago
and so far it's looking good. I'll report back tomorrow after
some more testing.

Fabian


signature.asc
Description: PGP signature

Re: [RFC/RFT] calloutng

[Fabian Keil]

Alexander Motin m...@freebsd.org wrote:

 On 20.12.2012 15:26, Fabian Keil wrote:
  Alexander Motin m...@freebsd.org wrote:
 
  On 20.12.2012 12:56, Fabian Keil wrote:
  Alexander Motin m...@freebsd.org wrote:
 
  Experiments with dummynet shown ineffective support for very short
  tick-based callouts. New version fixes that, allowing to get as many
  tick-based callout events as hz value permits, while still be able to
  aggregate events and generating minimum of interrupts.
 
  Also this version modifies system load average calculation to fix some
  cases existing in HEAD and 9 branches, that could be fixed with new
  direct callout functionality.
 
  http://people.freebsd.org/~mav/calloutng_12_17.patch
 
  With this patch (and the previous one, I didn't test the others)
  my mouse cursor is occasionally not reacting for short amounts of
  time (less than a second, but long enough to be noticeable).

  Could you try to revert part of the patch, related to dev/atkbdc? I am
  not strong in details of that hardware, but in comments there mention
  that they are related. May be lost keyboard interrupts (which polling
  rate was increased to 1 second) cause PS/2 mouse delays.
 
  I reverted the changes to sys/dev/atkbdc/* about an hour ago
  and so far it's looking good. I'll report back tomorrow after
  some more testing.

 Thank you for the report. If it will be fine. you can try to reapply 
 that part of the patch, just changing line:
 callout_reset_flags(sc-callout, hz, atkbdtimeout, dev, C_PRELSET(0));
 to the:
 callout_reset_flags(sc-callout, hz/10, atkbdtimeout, dev, C_PRELSET(0));
 
 It should about to restore original polling interval, but still make it 
 more flexible then original.

With this change the mouse stops working completely after moving
the cursor a couple of pixels, at which point dmesg shows:
 
kbdc: TEST_AUX_PORT status:
kbdc: RESET_AUX return code:00fa
kbdc: RESET_AUX status:00aa
kbdc: RESET_AUX ID:

Using the keyboard frequently causes duplicated characters.

I'm aware of a problem in vanilla CURRENT where the mouse stops working
with similar looking messages when the cursor is being moved at the wrong
moment, but this happens less than once a week and I haven't been able to
track it down yet. It's possible that it's the same bug and your patch just
triggers it more reliable (two times in a row). I haven't seen the
duplicated-characters issue before, though.

Just for kicks I also tried:

callout_reset_flags(sc-callout, hz/100, atkbdtimeout, dev, C_PRELSET(0));

but with this modification I can't even enter my login password
and thus can't tell if the mouse would work.

Fabian


signature.asc
Description: PGP signature

cam-accessing programs locking up

[Fabian Keil]

Since a couple of weeks I occasionally notice that a command accessing
cd0 hangs and once that happens I haven't found a way to get cd0
working again through software without rebooting.

No kernel complaints are logged, but afterwards somewhat related
commands hang as well.

In this case I noticed that a mount of a DVD didn't succeed and
thus ctrl+c'd it to clean the disc, but the drive still ignored
the eject button and mount kept running in the background:

fk@r500 ~ $sudo procstat -kk $(pgrep mount)
PIDTID COMM TDNAME   KSTACK   
 2818 100458 mount_cd9660 -mi_switch+0x194 sleepq_wait+0x42 
_sleep+0x3a2 cam_periph_runccb+0x5a cdrunccb+0x4f cdcheckmedia+0xbf 
cdopen+0x131 g_disk_access+0x115 g_access+0x15e g_dev_open+0xd3 
devfs_open+0x218 VOP_OPEN_APV+0x44 vn_open_vnode+0x159 vn_open_cred+0x20c 
kern_openat+0x1fe amd64_syscall+0x5f9 Xfast_syscall+0xf7 

Trying to eject through software (which often works) resulted
in cdrecord hanging as well:

fk@r500 ~ $sudo procstat -kk $(pgrep cdrecord)
  PIDTID COMM TDNAME   KSTACK   
 4905 100982 cdrecord -mi_switch+0x194 sleepq_wait+0x42 
_sleep+0x3a2 cam_periph_getccb+0x62 cam_periph_ioctl+0x36 passioctl+0x7b 
devfs_ioctl_f+0x7b kern_ioctl+0x106 sys_ioctl+0xfd amd64_syscall+0x5f9 
Xfast_syscall+0xf7 

Looking for cam sysctl's to fiddle with resulted in sysctl -a
hanging after printing kern.cam.enc.emulate_array_devices: 1:

fk@r500 ~ $sudo procstat -kk $(pgrep sysctl)
  PIDTID COMM TDNAME   KSTACK   
 4938 100989 sysctl   -mi_switch+0x194 
sleepq_timedwait+0x42 _sleep+0x1c9 g_waitfor_event+0xc2 sysctl_disks+0x49 
sysctl_root+0x18d userland_sysctl+0x145 sys___sysctl+0xaa amd64_syscall+0x5f9 
Xfast_syscall+0xf7 

zpool export, zpool list and an aborted zpool iostat
where affected as well:

fk@r500 ~ $sudo procstat -kk $(pgrep zpool)
Password:
  PIDTID COMM TDNAME   KSTACK   
 5131 100976 zpool-mi_switch+0x194 sleepq_wait+0x42 
_sx_xlock_hard+0x4ff _sx_xlock+0x75 spa_all_configs+0x5c 
zfs_ioc_pool_configs+0x29 zfsdev_ioctl+0xe6 devfs_ioctl_f+0x7b kern_ioctl+0x106 
sys_ioctl+0xfd amd64_syscall+0x5f9 Xfast_syscall+0xf7 
 5013 101502 zpool-mi_switch+0x194 sleepq_wait+0x42 
_sx_xlock_hard+0x4ff _sx_xlock+0x75 zvol_remove_minors+0x70 
zfs_ioc_pool_export+0x47 zfsdev_ioctl+0xe6 devfs_ioctl_f+0x7b kern_ioctl+0x106 
sys_ioctl+0xfd amd64_syscall+0x5f9 Xfast_syscall+0xf7 
 3408 100484 zpool-mi_switch+0x194 sleepq_wait+0x42 
_sx_xlock_hard+0x4ff _sx_xlock+0x75 spa_open_common+0x7a spa_get_stats+0x5b 
zfs_ioc_pool_stats+0x2c zfsdev_ioctl+0xe6 devfs_ioctl_f+0x7b kern_ioctl+0x106 
sys_ioctl+0xfd amd64_syscall+0x5f9 Xfast_syscall+0xf7 

Fabian


signature.asc
Description: PGP signature

Re: manual page | zpool-features

[Fabian Keil]

Darrel levi...@iglou.com wrote:

 OpenBSD Packet Filter seems to have broken between 9.0 and 9.1, as it did 
 from 8.2 to 9.0.  I built stable/9 and it was not fixed.  Since I like to 
 run Packet Filter, I ran these commands:
 
 # cd /usr
 # svn co svn://svn.freebsd.org/base/head src
 
 Then I checked /usr/src/UPDATING and found this:
 
 20120828:
  A new ZFS feature flag com.delphix:empty_bpobj has been merged
  to -HEAD. Pools that have empty_bpobj in active state can not be
  imported read-write with ZFS implementations that do not support
  this feature. For more information read the zpool-features(5)
  manual page.
 
 Unfortunately, I do not have a manual page for zpool-features.

It should be part of the checkout. Try:

man /usr/src/cddl/contrib/opensolaris/cmd/zpool/zpool-features.5

 Does this mean that I can not update from 9 to 10?

No.

Fabian


signature.asc
Description: PGP signature

Re: [HEADSUP] geli(4) weak master key generation on -CURRENT

[Fabian Keil]

Simon L. B. Nielsen si...@freebsd.org wrote:

 On Tue, Aug 21, 2012 at 1:05 PM, Ulrich Spörlein u...@freebsd.org wrote:
  On Mon, 2012-08-20 at 22:24:56 +0100, Simon L. B. Nielsen wrote:

  -CURRENT users of geli(4) should be advised that, a geli(4) device may
  have weak master key, if the provider is created on -CURRENT system
  built against source code between r238116 (Jul 4 17:54:17 2012 UTC)
  and r239184 (non-inclusive, Aug 10 18:43:29 2012 UTC).
 
  One can verify if its provider was created with weak keys by running:
 
# geli dump provider | grep version
 
  If the version is 7 and the system did not include this fix (r239184)
  when provider was initialized, then the data has to be backed up,
  underlying provider overwritten with random data, system upgraded and
  provider recreated.

  I haven't read commit mails in a very long time, but is there code in
  place that will issue a warning upon geli attach if version 7 is
  detected? While -CURRENT is not supported, there might be a lot of disks
  initialized with version 7 and they'll eventually be upgraded to
  10.0-RELEASE (the OS, not necessarily the geli volumes).
 
 No, the bad code was only in head for about a month. I'm fine with
 having a warning, but somebody has to code it.

The weak keys weren't stored on disk, but generated at attach-time.

A patched kernel will generate different keys which means it
shouldn't be backwards compatible to a vulnerable kernel as
far as reading and writing geli version 7 is concerned.

If a user doesn't follow the recommended mitigation steps and simply
updates the kernel without migrating the data first, he shouldn't
be able to read the encrypted data written with the previous kernel
version, which I consider kinda hard to miss.

I believe if there really were a lot of disks initialized with
affected kernels, there would have been at least a couple of
complaints on the mailing lists already.

Fabian


signature.asc
Description: PGP signature

Re: fetch(1) fails with https:// - Authentication error

[Fabian Keil]

Doug Barton do...@freebsd.org wrote:

 On 07/13/2012 21:21, Jan Beich wrote:
  It seems recent OpenSSL update broke fetch(1) for me.
  
$ diff -u $SRC_BASE/crypto/openssl/apps/openssl.cnf /etc/ssl/openssl.cnf
$ fetch https://foo/bar
fetch: https://foo/bar: Authentication error
  
  Same error as with the patch for 1.0.0d from a year ago and
  same workaround - s/SSLv23_client_method/SSLv3_client_method/.
 
 FWIW, I have a gcc world and I'm not seeing this problem with r238444:
 
 fetch https://www.isc.org/
 fetch: https://www.isc.org/: size of remote file is not known
 fetch.out   33 kB  227 kBps

I have a gcc world too, but while https://www.isc.org/ worked for
me as well, using others I got the same behaviour as Jan:

fk@r500 ~ $fetch -o /dev/null https://lists.sourceforge.net
fetch: https://lists.sourceforge.net: Authentication error

For some I got an additional error message:

fk@r500 ~ $fetch -o /dev/null https://www.google.com
34382938280:error:1408D07B:SSL routines:SSL3_GET_KEY_EXCHANGE:bad 
signature:/usr/src/secure/lib/libssl/../../../crypto/openssl/ssl/s3_clnt.c:1811:
fetch: https://www.google.com: Authentication error

Letting libfetch use SSLv3_client_method instead of SSLv23_client_method
as suggested worked around the issue for me as well.

Fabian


signature.asc
Description: PGP signature

Re: [RFT] llquantize for FreeBSD's dtrace

[Fabian Keil]

Pedro Giffuni p...@freebsd.org wrote:

 --- Mar 26/6/12, Mark Peek m...@freebsd.org ha scritto:

  Try this, change the assert on line 1429 in file dt_cc.c
  from:
  
  assert(!(arg  (UINT16_MAX  args[i].shift)));
  
  to
  
  assert(!(arg  ((uint64_t)UINT16_MAX 
  args[i].shift)));
  
 
 This certainly looks correct. Thanks Mark !
 
 I updated the patch:
 
 http://people.freebsd.org/~pfg/patches/patch-dtrace-llquantize

Thanks a lot. Seems to work for me:

fk@r500 /usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize 
$for t in tst.*.d; do sudo dtrace -s $t  $t.myout; diff $t.out $t.myout  
echo success for $t; done
success for tst.bases.d
success for tst.basic.d
success for tst.negorder.d
success for tst.negvalue.d
success for tst.normal.d
success for tst.range.d
success for tst.steps.d
success for tst.trunc.d
fk@r500 /usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize 
$for t in err.*.d; do sudo dtrace -s $t
dtrace: failed to compile script err.D_LLQUANT_FACTOREVEN.nodivide.d: line 28: 
llquantize( ) factor (argument #1) must evenly divide the number of steps per 
magnitude (argument #4), and the number of steps per magnitude must evenly 
divide a power of the factor
dtrace: failed to compile script err.D_LLQUANT_FACTOREVEN.notfactor.d: line 28: 
llquantize( ) factor (argument #1) must evenly divide the number of steps per 
magnitude (argument #4), and the number of steps per magnitude must evenly 
divide a power of the factor
dtrace: failed to compile script err.D_LLQUANT_FACTORMATCH.d: line 29: 
llquantize( ) factor (argument #1) doesn't match previous declaration: expected 
10, found 3
dtrace: failed to compile script err.D_LLQUANT_FACTORNSTEPS.d: line 28: 
llquantize( ) factor (argument #1) must be less than or equal to the number of 
linear steps per magnitude (argument #4)
dtrace: failed to compile script err.D_LLQUANT_FACTORSMALL.d: line 28: 
llquantize( ) factor (argument #1) must be two or more
dtrace: failed to compile script err.D_LLQUANT_FACTORTYPE.d: line 29: 
llquantize( ) argument #1 (factor) must be an integer constant
dtrace: failed to compile script err.D_LLQUANT_FACTORVAL.d: line 28: 
llquantize( ) argument #1 (factor) must be an unsigned 16-bit quantity
dtrace: failed to compile script err.D_LLQUANT_HIGHMATCH.d: line 29: 
llquantize( ) high magnitude (argument #3) doesn't match previous declaration: 
expected 10, found 11
dtrace: failed to compile script err.D_LLQUANT_HIGHTYPE.d: line 29: llquantize( 
) argument #3 (high magnitude) must be an integer constant
dtrace: failed to compile script err.D_LLQUANT_HIGHVAL.d: line 28: llquantize( 
) argument #3 (high magnitude) must be an unsigned 16-bit quantity
dtrace: failed to compile script err.D_LLQUANT_LOWMATCH.d: line 29: llquantize( 
) low magnitude (argument #2) doesn't match previous declaration: expected 0, 
found 1
dtrace: failed to compile script err.D_LLQUANT_LOWTYPE.d: line 29: llquantize( 
) argument #2 (low magnitude) must be an integer constant
dtrace: failed to compile script err.D_LLQUANT_LOWVAL.d: line 28: llquantize( ) 
argument #2 (low magnitude) must be an unsigned 16-bit quantity
dtrace: failed to compile script err.D_LLQUANT_MAGRANGE.d: line 28: llquantize( 
) high magnitude (argument #3) must be greater than low magnitude (argument #2)
dtrace: failed to compile script err.D_LLQUANT_MAGTOOBIG.d: line 28: 
llquantize( ) factor (10) raised to power of high magnitude (100) overflows 
64-bits
dtrace: failed to compile script err.D_LLQUANT_NSTEPMATCH.d: line 29: 
llquantize( ) linear steps per magnitude (argument #4) doesn't match previous 
declaration: expected 10, found 100
dtrace: failed to compile script err.D_LLQUANT_NSTEPTYPE.d: line 29: 
llquantize( ) argument #4 (linear steps per magnitude) must be an integer 
constant
dtrace: failed to compile script err.D_LLQUANT_NSTEPVAL.d: line 28: llquantize( 
) argument #4 (linear steps per magnitude) must be an unsigned 16-bit quantity

Fabian


signature.asc
Description: PGP signature

Re: dtrace walltimestamp

[Fabian Keil]

Fabian Keil freebsd-lis...@fabiankeil.de wrote:

 At least on my system, timestamp offsets can only can be relied
 on with either kern.timecounter.hardware=TSC or with C3
 states disabled, though.
 
 Measuring the elapsed time (in ms) between events that happen
 in roughly 1 second intervals with kern.timecounter.hardware=HPET
 and dev.cpu.0.cx_lowest=C2:
 
   elapsed
value  - Distribution - count
  990 | 0
 1000 |@@@  57
 1010 | 0
 1020 | 0
 1030 |@1
 1040 | 0
 
   elapsed avg1007
 
 And doing the same with dev.cpu.0.cx_lowest=C3:
 
   elapsed
value  - Distribution - count
   40 | 0
   50 |@@@  28
   60 |@@@  10
   70 |@@@  5
   80 |@1
   90 | 0
  100 |@2
  110 |@2
  120 |@2
  130 | 0
  140 |@1
  150 |@1
  160 |@1
  170 |@1
  180 | 0
  190 | 0
  200 | 0
  210 | 0
  220 |@1
  230 |@1
  240 | 0
  250 | 0
  260 | 0
  270 | 0
  280 | 0
  290 |@1
  300 |@1
  310 | 0
  320 |@1
  330 | 0
 
   elapsed avg  90

Copying over some code from mips seems to fix this:
http://www.freebsd.org/cgi/query-pr.cgi?pr=amd64/169379

Fabian


signature.asc
Description: PGP signature

Re: [RFT] llquantize for FreeBSD's dtrace

[Fabian Keil]

Pedro Giffuni p...@freebsd.org wrote:

 I am not a Dtrace user (yet) but I started to port the Log/linear
 quantizations from Illumos:
 
 http://dtrace.org/blogs/bmc/2011/02/08/llquantize/
 
 Apparently this patch should do it:
 
 http://people.freebsd.org/~pfg/patches/patch-llquantize-complete
 
 Unfortunately when I tried to build current with Dtrace support,
 my i386 Virtualbox VM got stuck in ctfmerge so this is
 completely untested.
 
 Testers that know how to use it are welcome :).

I applied it on 10-CURRENT amd64 from /usr/src with patch -p0
without any conflicts, but it doesn't appear to be working.

The example from the blog post above triggers an assertion
that is still reproducible when reducing the test case:

fk@r500 /tmp $sudo dtrace -n 'tick-1ms{@ = llquantize(i++, 10, 0, 6, 20);}'
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.

Changing the i++ to i seems to trigger a different bug
(or at least doesn't behave like I would expect):

fk@r500 /tmp $sudo dtrace -n 'tick-1ms{@ = llquantize(i, 10, 0, 6, 20);}'
dtrace: invalid probe specifier tick-1ms{@ = llquantize(i, 10, 0, 6, 20);}: in 
action list: failed to resolve i: Unknown variable name

Replacing the i with a zero behaves similar to the version that uses i++ again:

fk@r500 /tmp $sudo dtrace -n 'tick-1ms{ i = 0; @ = llquantize(0, 10, 0, 6, 
20);}'
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.

fk@r500 /tmp $gdb741 $(which dtrace) dtrace.core
[GDB will not be able to debug user-mode threads: Undefined symbol 
td_thr_getxmmregs]
GNU gdb (GDB) 7.4.1 [GDB v7.4.1 for FreeBSD]
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type show copying
and show warranty for details.
This GDB was configured as x86_64-portbld-freebsd10.0.
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/...
Reading symbols from /usr/sbin/dtrace...done.
[New process 100454]
Core was generated by `dtrace'.
Program terminated with signal 6, Aborted.
#0  0x0008019a26ac in thr_kill () at thr_kill.S:3
3   RSYSCALL(thr_kill)
(gdb) where
#0  0x0008019a26ac in thr_kill () at thr_kill.S:3
#1  0x00080082ff5c in _thr_send_sig (thread=optimized out, sig=6) at 
/usr/src/lib/libthr/thread/thr_sig.c:113
#2  0x0008008305b6 in _raise (sig=0) at 
/usr/src/lib/libthr/thread/thr_sig.c:505
#3  0x000801a517d3 in abort () at /usr/src/lib/libc/stdlib/abort.c:65
#4  0x000800a91c60 in __assert (line=optimized out, file=optimized out, 
expr=optimized out) at 
/usr/src/cddl/lib/libdtrace/../../../cddl/compat/opensolaris/include/assert.h:56
#5  dt_compile_agg (dtp=0x80243f000, dnp=0x803e223e0, sdp=0x803e17140) at 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c:1366
#6  0x000800a9257f in dt_compile_one_clause (pnp=optimized out, 
cnp=optimized out, dtp=optimized out)
at 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c:1597
#7  dt_compile_clause (dtp=0x80243f000, cnp=0x803e23040) at 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c:1628
#8  0x000800a94441 in dt_compile (dtp=0x80243f000, context=362, 
pspec=DTRACE_PROBESPEC_NAME, arg=0x0, cflags=128, argc=1, argv=0x802417040, 
fp=0x0,
s=0x7fffd9ca tick-1ms{ i = 0; @ = llquantize(i, 10, 0, 6, 20);}) at 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c:2396
#9  0x000800a948bc in dtrace_program_strcompile (dtp=0x18866, s=optimized 
out, spec=DTRACE_PROBESPEC_PROVIDER, cflags=0, argc=-2123430480, 
argv=optimized out)
at 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c:2460
#10 0x00405ae4 in compile_str (dcp=0x802418e00) at 
/usr/src/cddl/usr.sbin/dtrace/../../../cddl/contrib/opensolaris/cmd/dtrace/dtrace.c:766
#11 0x00403b41 in main (argc=optimized out, argv=0x7fffd668) at 
/usr/src/cddl/usr.sbin/dtrace/../../../cddl/contrib/opensolaris/cmd/dtrace/dtrace.c:1632

Fabian


signature.asc
Description: PGP signature

Re: [RFT] llquantize for FreeBSD's dtrace

[Fabian Keil]

Pedro Giffuni p...@freebsd.org wrote:

 Hello Fabian;
 
 --- Sab 23/6/12, Fabian Keil ha scritto:
 
  Pedro Giffuni p...@freebsd.org wrote:
  
   I am not a Dtrace user (yet) but I started to port the
  Log/linear
   quantizations from Illumos:
   
   http://dtrace.org/blogs/bmc/2011/02/08/llquantize/
   
   Apparently this patch should do it:
   
   http://people.freebsd.org/~pfg/patches/patch-llquantize-complete
   
   Unfortunately when I tried to build current with Dtrace
   support, my i386 Virtualbox VM got stuck in ctfmerge so
   this is completely untested.
   
   Testers that know how to use it are welcome :).
  
  I applied it on 10-CURRENT amd64 from /usr/src with patch
  -p0 without any conflicts, but it doesn't appear to be
  working.
  
  The example from the blog post above triggers an assertion
  that is still reproducible when reducing the test case:
  
  fk@r500 /tmp $sudo dtrace -n 'tick-1ms{@ = llquantize(i++,
  10, 0, 6, 20);}'
  Assertion failed: (!(arg  (UINT16_MAX 
  args[i].shift))), file
  /usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
  line 1429.
 
 
 Thanks for testing!
 
 It seems like the syntax has changed from the time the
 example from the blog was made. The code says:
 
 /*
  * For log/linear quantizations, we have between one and five
  * arguments in addition to the expression:
  *
  *arg1 = Factor
  *arg2 = Low magnitude
  *arg3 = High magnitude
  *arg4 = Number of steps per magnitude
  *arg5 = Quantization increment value (defaults to 1)
  */
 
 
 My suggestion would be to instead try using the test
 scripts in
 cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize/
 
 err.D_LLQUANT_FACTORSMALL.d (for example) has
 
 @ = llquantize(0, 1, 0, 10, 10);

The problem appears to be unrelated to the syntax change:

fk@r500 /usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize 
$sudo dtrace -s err.D_LLQUANT_FACTORSMALL.d
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.
fk@r500 /usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize 
$sudo dtrace -s tst.bases.d
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.
fk@r500 /usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize 
$sudo dtrace -s tst.negvalue.d
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.
fk@r500 /usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize 
$sudo dtrace -s tst.steps.d
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.

root@r500:/root # dtrace -s 
/usr/src/cddl/contrib/opensolaris/cmd/dtrace/test/tst/common/llquantize/tst.steps.d
Assertion failed: (!(arg  (UINT16_MAX  args[i].shift))), file 
/usr/src/cddl/lib/libdtrace/../../../cddl/contrib/opensolaris/lib/libdtrace/common/dt_cc.c,
 line 1429.
Abort (core dumped)

Fabian


signature.asc
Description: PGP signature

Re: DTrace broken on 9.0-Release?

[Fabian Keil]

Ryan Goodfellow rgood...@eecs.wsu.edu wrote:

 Today I downloaded and installed FreeBSD 9.0-RELEASE and followed the
 directions from http://wiki.freebsd.org/DTrace to get DTrace up and
 running.  The output of DTrace instrumenting a simple program, however,
 is not correct.  The program is as follows:
 
 // test.cc
 #includecstdlib
 
 int main(void) {
   for(int i = 0; i  5; i++) {
 malloc(47);
   }
 }
 
 then compiling and running DTrace as follows:
 
 g++ test.cc -o test
 
 dtrace -n 'pid$target::malloc:entry{ }' -c ./test
 
 
 The correct output for this example is something to the tune of:
 
 dtrace: description 'pid$target::malloc:entry' matched 2 probes
 dtrace: pid 95236 has exited
 CPU IDFUNCTION:NAME
   0 188748 malloc:entry 
   0 188748 malloc:entry 
   0 188748 malloc:entry 
   0 188748 malloc:entry 
   0 188748 malloc:entry 
 
 (this from a machine with the same code running DTrace)
 
 The DTrace session should also make an immediate exit on completion. On
 FreeBSD I have the following CPU IDFUNCTION:NAME
   2  42213 malloc:entry 
 
 and the execution does either not exit on it's own or hangs, it requires
 a ctrl-c.

Doesn't work for me either on 10-CURRENT amd64.
Converting it to C doesn't make a difference, it works if
one changes the loop to for (;;), though.

 I followed the instructions from the FreeBSD site exactly, compiling and
 installing the custom kernel.  I used both clang++ and g++ for
 compilation with the same result.  The system has even completely hung
 on other attempts.
 
 Is DTrace not something that should be relied upon in FreeBSD?  I have
 also tried this on the latest 10-CURRENT build with the same result.

In my opinion the problem with DTrace on FreeBSD is that while it's
known to be incomplete, there doesn't seem to be documentation
available about which parts are supposed to work already and which
aren't.

For example the trivial example program at:
http://wiki.freebsd.org/DTrace/userland (which works for me) doesn't
actually use a counting loop, so maybe dtracing your example program
isn't supposed to work yet and never did on FreeBSD.

Without documentation it's hard to tell.

Fabian


signature.asc
Description: PGP signature

Re: svn commit: r235478 - head/cddl/contrib/opensolaris/cmd/zpool

[Fabian Keil]

Pawel Jakub Dawidek p...@freebsd.org wrote:

 On Tue, May 15, 2012 at 05:07:30PM +, Andriy Gapon wrote:
  Author: avg
  Date: Tue May 15 17:07:29 2012
  New Revision: 235478
  URL: http://svn.freebsd.org/changeset/base/235478
  
  Log:
zpool_do_import: use /dev instead of /dev/dsk as a default

This affects behavior of zpool import without -d option.
 
 How does it affect 'zpool import' behaviour? On FreeBSD when -d is not
 given we should not scan entire /dev/, but take all available GEOM
 providers from the GEOM.

The problem was discussed in this thread:
http://lists.freebsd.org/pipermail/freebsd-current/2012-May/033805.html
(so I set Followup-To: freebsd-current@)

Under some condition zpool import seems to do an lstat() on
the searchdirs[0] default and bail out if it's unsuccessful.

Here's a truss excerpt from such a failure:

open(/dev/zfs,O_RDWR,030730440)= 3 (0x3)
open(/dev/zero,O_RDONLY,0666)  = 4 (0x4)
open(/etc/zfs/exports,O_RDONLY,0666)   = 5 (0x5)
geteuid()= 0 (0x0)
lstat(/dev,{ mode=dr-xr-xr-x ,inode=2,size=512,blksize=4096 }) = 0 (0x0)
lstat(/dev/dsk,0x7fff83c0) ERR#2 'No such file or 
directory'
cannot open '/dev/dsk': must be an absolute path
write(2,cannot open '/dev/dsk': must be ...,49) = 49 (0x31)
close(3) = 0 (0x0)

Currently (different kernel and world) I get:

open(/dev/zfs,O_RDWR,030730440)= 3 (0x3)
open(/dev/zero,O_RDONLY,0666)  = 4 (0x4)
open(/etc/zfs/exports,O_RDONLY,0666)   = 5 (0x5)
__sysctl(0x7fff7d60,0x2,0x7fff7da0,0x7fff7e08,0x801495259,0x13) = 0 
(0x0)
__sysctl(0x7fff7da0,0x4,0x8016a3f80,0x7fff7e50,0x0,0x0) = 0 (0x0)
ioctl(3,0xd5985a04 { IORW 0x5a('Z'), 4, 5528 },0x7e70) = 0 (0x0)
ioctl(3,0xd5985a05 { IORW 0x5a('Z'), 5, 5528 },0x7e30) = 0 (0x0)
ioctl(3,0xd5985a05 { IORW 0x5a('Z'), 5, 5528 },0x7e30) = 0 (0x0)
lstat(/dev,{ mode=dr-xr-xr-x ,inode=2,size=512,blksize=4096 }) = 0 (0x0)
open(/dev/,O_RDONLY,0371)  = 6 (0x6)

which seems to imply that zpool didn't use the searchdirs[0] default
at all, so a version before r235478 probably would have worked as well.

Fabian


signature.asc
Description: PGP signature

Re: Default directory used for 'zpool import' broken (/dev/dsk)?

[Fabian Keil]

Andriy Gapon a...@freebsd.org wrote:

 on 13/05/2012 11:53 Bruce Cran said the following:
  When running 'zpool import' without -d I get the error:
  cannot open '/dev/dsk': must be an absolute path
  
  zpool(8) suggests the default should have been updated for FreeBSD:
  If the -d option is not specified, this command searches for devices
  in /dev
  
  Was this broken recently?

 Not sure, but maybe /dev/dsk is recorded somewhere in the pool metadata
 or in zpool.cache.  It could have happened with the older version of the
 code. I think that you could check that with zdb.  I think that a fresh
 import should fix it, though.

The following patch seems to work for me:


commit 7ec69700f2d6944a61f5c7a826e67f46fa160221
Author: Fabian Keil f...@fabiankeil.de
Date:   Mon May 12 16:53:56 2012 +0200

Default to searching vdevs in /dev. /dev/dsk doesn't exist on FreeBSD.

Fixes import issues if no cachefile exists and -d isn't used:

fk@r500 ~ $sudo zpool import wde2
cannot open '/dev/dsk': must be an absolute path

diff --git a/cddl/contrib/opensolaris/cmd/zpool/zpool_main.c 
b/cddl/contrib/opensolaris/cmd/zpool/zpool_main.c
index fe76250..5d1e454 100644
--- a/cddl/contrib/opensolaris/cmd/zpool/zpool_main.c
+++ b/cddl/contrib/opensolaris/cmd/zpool/zpool_main.c
@@ -1909,7 +1909,7 @@ zpool_do_import(int argc, char **argv)
 
if (searchdirs == NULL) {
searchdirs = safe_malloc(sizeof (char *));
-   searchdirs[0] = /dev/dsk;
+   searchdirs[0] = /dev;
nsearch = 1;
}


The cachefile part is speculation ...

Fabian


signature.asc
Description: PGP signature

Re: Snapshot listing speedup.

[Fabian Keil]

Pawel Jakub Dawidek p...@freebsd.org wrote:

 If you have many snapshots and you were complaining that listing them
 takes a lot of time, you may find the commit below useful.

Indeed.
 
 It only works if your listing is limited to snapshot names and you want
 to sort also by snapshot name (by default snapshots are sorted by
 creation time).

After adjusting my backup script, I can confirm that gathering
the available snapshots is more than 200 times faster now.

Previously figuring out what to send frequently took more
time than actually sending the data.

Thanks a lot.

Fabian


signature.asc
Description: PGP signature

Re: Stop scheduler on panic

[Fabian Keil]

Alexander Motin m...@freebsd.org wrote:

 On 11/17/11 13:14, Kostik Belousov wrote:
  On Thu, Nov 17, 2011 at 11:29:02AM +0200, Alexander Motin wrote:
  On 11/17/11 11:06, Kostik Belousov wrote:
  On Thu, Nov 17, 2011 at 10:40:58AM +0200, Alexander Motin wrote:
  On 11/17/11 10:15, Kostik Belousov wrote:
  On Thu, Nov 17, 2011 at 01:07:38AM +0200, Alexander Motin wrote:
  On 17.11.2011 00:21, Andriy Gapon wrote:
  on 16/11/2011 21:27 Fabian Keil said the following:
  Kostik Belousovkostik...@gmail.com  wrote:
 
  I was tricked into finishing the work by Andrey Gapon, who developed
  the patch to reliably stop other processors on panic.  The patch
  greatly improves the chances of getting dump on panic on SMP host.
 
  I tested the patch trying to get a dump (from the debugger) for
  kern/162036, which currently results in the double fault reported in:
  http://lists.freebsd.org/pipermail/freebsd-current/2011-September/027766.html
 
  It didn't help, but also didn't make anything worse.

  The mi_switch recursion looks very familiar to me:
  mi_switch() at mi_switch+0x270
  critical_exit() at critical_exit+0x9b
  spinlock_exit() at spinlock_exit+0x17
  mi_switch() at mi_switch+0x275
  critical_exit() at critical_exit+0x9b
  spinlock_exit() at spinlock_exit+0x17
  [several pages of the previous three lines skipped]
  mi_switch() at mi_switch+0x275
  critical_exit() at critical_exit+0x9b
  spinlock_exit() at spinlock_exit+0x17
  intr_even_schedule_thread() at intr_event_schedule_thread+0xbb
  ahci_end_transaction() at ahci_end_transaction+0x398
  ahci_ch_intr() at ahci_ch_intr+0x2b5
  ahcipoll() at ahcipoll+0x15
  xpt_polled_action() at xpt_polled_action+0xf7
 
  In fact I once discussed with jhb this recursion triggered from a 
  different
  place.  To quote myself:
  avgspinlock_exit -  critical_exit -  mi_switch -  kdb_switch 
  -
  thread_unlock -  spinlock_exit -  critical_exit -  mi_switch -  
  ...
  avgin the kdb context
  avgthis issue seems to be triggered by td_owepreempt being true 
  at 
  the time
  kdb is entered
  avgand there of course has to be an initial spinlock_exit call 
  somewhere
  avgin my case it's because of usb keyboard
  avgI wonder if it would make sense to clear td_owepreempt right 
  before
  calling kdb_switch in mi_switch
  avginstead of in sched_switch()
  avgclearing td_owepreempt seems like a scheduler-independent 
  operation to me
  avgor is it better to just skip locking in usb when kdb_active 
  is set
  avg?
 
  The workaround described above should work in this case.
  Another possibility is to pessimize mtx_unlock_spin() implementations 
  to 
  check
  SCHEDULER_STOPPED() and to bypass any further actions in that case.  
  But 
  that
  would add unnecessary overhead to the sunny day code paths.
 
  Going further up the stack one can come up with the following 
  proposals:
  - check SCHEDULER_STOPPED() swi_sched() and return early
  - do not call swi_sched() from xpt_done() if we somehow know that we 
  are 
  in a
  polling mode
 
  There is no flag in CAM now to indicate polling mode, but if needed, 
  it 
  should not be difficult to add one and not call swi_sched().
 
  I have the following change for eons on my test boxes. Without it,
  I simply cannot get _any_ dump.

  That should be OK for kernel dumping. I was thinking about CAM abusing
  polling not only for dumping. But looking on cases where it does it now,
  may be it is better to rewrite them instead.
 
  So, should I interpret your response as 'Reviewed by ?
 
  It feels somehow dirty to me. I don't like these global variables. If
  you consider it is fine, proceed, I see no much harm. But if not, I can
  add polling flag to the CAM. Flip a coin for me. :)
  You promised to add the polling at summer' meeting in Kiev. Will you do
  it now ?
 
 Sorry, I've probably forgot. The patch is attached.

After rebasing on r227637 dumping core from the debugger works
and the backtrace is at least partly usable. PR updated.

Thanks a lot.

Fabian


signature.asc
Description: PGP signature

Re: Stop scheduler on panic

[Fabian Keil]

Kostik Belousov kostik...@gmail.com wrote:

 I was tricked into finishing the work by Andrey Gapon, who developed
 the patch to reliably stop other processors on panic.  The patch
 greatly improves the chances of getting dump on panic on SMP host.

I tested the patch trying to get a dump (from the debugger) for
kern/162036, which currently results in the double fault reported in:
http://lists.freebsd.org/pipermail/freebsd-current/2011-September/027766.html

It didn't help, but also didn't make anything worse.

Fabian


signature.asc
Description: PGP signature

Re: Fatal trap 12: page fault while in kernel mode -- Stopped at atomic_subtract_int+0x4

[Fabian Keil]

Fabian Keil freebsd-lis...@fabiankeil.de wrote:

 Fabian Keil freebsd-lis...@fabiankeil.de wrote:
 
  I pretty reproducible get the following (handtranscribed) panic
  when sending an zfs snapshot to geli provider based on an USB
  stick that disappears (due to a bug, or because it's unplugged): 
  
  Fatal trap 12: page fault while in kernel mode
  cpuid = 0: apic id = 00
  fault virtual address = 0x288
  fault code= supervisor write data, page not present
  instruction pointer   = 0x20:0x808e2984
  stack pointer = 0x28:0xff800023fba0
  frame pointer = 0x28:0xff800023fbb0
  code segment  = base 0x0, limit 0xf, type 0x1b
= DPL 0, pres 1, long 1, def32 0, gran 1
  processor eflags  = interrupt enabled, resume, IOPL = 0
  current process   = 13 (g_up)
  [ thread pid 13 tid 100010 ]
  Stopped atatomic_subtract_int+0x4: lock subl %esi,(%rdi)

 Here's another one, again with recent HEAD.
 
 This time the USB stick disappeared while the pool was
 being scrubbed and dumping actually worked. The stick
 seems to reproducibly disappear after scrubbing it for
 a while and the panic seems to be reproducible as well.
 
 The stack trace looks a bit different, but I'm not sure if
 this is because it's a slightly different situation or because
 of changes in HEAD.

They are different and can be reproduced independently.
I filed PRs for them:
http://www.freebsd.org/cgi/query-pr.cgi?pr=162010
http://www.freebsd.org/cgi/query-pr.cgi?pr=162036

Fabian


signature.asc
Description: PGP signature

Re: Fatal trap 12: page fault while in kernel mode -- Stopped at atomic_subtract_int+0x4

[Fabian Keil]

Fabian Keil freebsd-lis...@fabiankeil.de wrote:

 I pretty reproducible get the following (handtranscribed) panic
 when sending an zfs snapshot to geli provider based on an USB
 stick that disappears (due to a bug, or because it's unplugged): 
 
 Fatal trap 12: page fault while in kernel mode
 cpuid = 0: apic id = 00
 fault virtual address = 0x288
 fault code  = supervisor write data, page not present
 instruction pointer   = 0x20:0x808e2984
 stack pointer = 0x28:0xff800023fba0
 frame pointer = 0x28:0xff800023fbb0
 code segment  = base 0x0, limit 0xf, type 0x1b
   = DPL 0, pres 1, long 1, def32 0, gran 1
 processor eflags  = interrupt enabled, resume, IOPL = 0
 current process   = 13 (g_up)
 [ thread pid 13 tid 100010 ]
 Stopped atatomic_subtract_int+0x4: lock subl %esi,(%rdi)
 db where
 Tracing pid 13 tid 100010 td 0xfe00027998c0
 atomic_subtract_int() at atomic_subtract_int+0x4
 g_io_schdule_up() at g_io_schedule_up+0xa6
 g_up_procbody() at g_up_procbody+0x5c
 fork_exit() at fork_exit+0x11f
 fork_trampoline() at fork_trampoline+0xe
 --- trap 0, rip = 0, rsp = 0xff800023fd00, rbp 0 ---
 
 It seems to be important that ZFS is actually writing to the stick.
 If the stick is unplugged while the operation is stalled for other
 reasons, this particular panic doesn't seem to occur.
 
 While I end up in the debugger, dumping core doesn't work
 and produces a double fault and a bunch of duplicated
 messages (again handtranscribed):

The duplicated messages have been recently fixed.
 
 db dump
 Dumping 443 out of 1974 MB: Dumping 443 out of 1974 MB
 
 Fatal double fault
 Fatal double fault
 rip = 0x8066a9e0
 rip = 0x8066a9e0
 rsp = 0xff800023c000
 rsp = 0xff800023c000
 rbp = 0xff800023c040
 rbp = 0xff800023c040
 cpuid = 0; cpuid = 0; apic id = 00
 apic id = 00
 panic: double fault
 panic: double fault
 cpuid = 0
 cpuid = 0
 KDB: stack backtrace:
 KDB: stack backtrace:
 db_trac_self_wrapper() at db_trace_self_wrapper+0x2a
 kdb_backtrace() at kdb_backtrace+0x37
 panic() at panic+0x187
 dblfault_handler() at dblfault_handler+0xa4
 Xdblfault() at Xdblfault+0xa8
 --- trap 0x17, rip = 0x8066a9e8, rsp = 0x80e56158, rbp = 
 0xff800023c040 ---
 mi_switch() at mi_switch+0x270
 critical_exit() at critical_exit+0x9b
 spinlock_exit() at spinlock_exit+0x17
 mi_switch() at mi_switch+0x275
 critical_exit() at critical_exit+0x9b
 spinlock_exit() at spinlock_exit+0x17
 [several pages of the previous three lines skipped]
 mi_switch() at mi_switch+0x275
 critical_exit() at critical_exit+0x9b
 spinlock_exit() at spinlock_exit+0x17
 intr_even_schedule_thread() at intr_event_schedule_thread+0xbb
 ahci_end_transaction() at ahci_end_transaction+0x398
 ahci_ch_intr() at ahci_ch_intr+0x2b5
 ahcipoll() at ahcipoll+0x15
 xpt_polled_action() at xpt_polled_action+0xf7
 
 I first noticed the problem with CURRENT from a week ago,
 but given that USB sticks don't usually disappear for me
 while sending snapshots to them, the problem might not
 be new.
 
 I'm using amd64, the panic above is from a custom kernel
 without WITNESS and INVARIANTS, but enabling them doesn't
 seem to affect the trace before the double fault.
 
 I wasn't able to reproduce the panic by unplugging the stick
 while writing to the pool using dd (but only tried once).

Here's another one, again with recent HEAD.

This time the USB stick disappeared while the pool was
being scrubbed and dumping actually worked. The stick
seems to reproducibly disappear after scrubbing it for
a while and the panic seems to be reproducible as well.

The stack trace looks a bit different, but I'm not sure if
this is because it's a slightly different situation or because
of changes in HEAD.

fk@r500 /usr/crash $kgdb kernel.3/kernel vmcore.3
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type show copying to see the conditions.
There is absolutely no warranty for GDB.  Type show warranty for details.
This GDB was configured as amd64-marcel-freebsd...

Unread portion of the kernel message buffer:
ugen7.2: Generic at usbus7 (disconnected)
umass0: at uhub7, port 2, addr 2 (disconnected)
(da0:umass-sim0:0:0:0): Request completed with CAM_REQ_CMP_ERR
(da0:umass-sim0:0:0:0): Retrying command
(da0:umass-sim0:0:0:0): Selection timeout
(da0:umass-sim0:0:0:0): Retrying command
(da0:umass-sim0:0:0:0): Selection timeout
(da0:umass-sim0:0:0:0): Retrying command
(da0:umass-sim0:0:0:0): Selection timeout
(da0:umass-sim0:0:0:0): Retrying command
(pass2:umass-sim0:0:0:0): lost device
(pass2:umass-sim0:0:0:0): removing device entry
(da0:umass-sim0:0:0:0): lost device - 1 outstanding
(da0:umass-sim0:0:0:0): Error 6, Retries exhausted
(da0:umass-sim0:0:0:0): oustanding 0
GEOM_ELI: Crypto WRITE request

Re: A patch for a bug in the dtrace command...

[Fabian Keil]

George Neville-Neil g...@freebsd.org wrote:

 I have found that the dtrace command on FreeBSD, in both STABLE and HEAD, 
 does not print out
 aggregations properly, likely due to the difference in how Solaris and 
 FreeBSD signals work.
 For example, this one liner will give no output:
 
 sudo dtrace -n 'syscall:::entry { @[execname] = quantize(arg0); }'

Acutally it works when not using sudo or when killing dtrace by
sending a SIGTERM instead of using the keyboard. Of course it's still
a bug.

 While is should print this:
 
 dtrace -n 'syscall:::entry { @[execname] = quantize(arg0); }'
 dtrace: description 'syscall:::entry ' matched 1028 probes
 ^C
 
   nrpe2 
value  - Distribution - count
2 | 0
4 | 12   
8 | 0
 
   sshd  
value  - Distribution - count
0 | 0
1 |@@   5
2 |@@   7
4 | 0
8 | 8
   16 | 0
 
 etc.
 
 I have made the following patch, but I'd be interested in people testing and 
 commenting on it.

I do not know whether dtrace or sudo is responsible for the problem,
but I can confirm that the patch works for me. Thanks a lot.

Fabian


signature.asc
Description: PGP signature