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  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  wrote:

> Konstantin Belousov  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  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]

Konstantin Belousov  wrote:

> On Wed, Dec 16, 2015 at 12:21:16PM +0100, Fabian Keil wrote:
> > Konstantin Belousov  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

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]

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  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},

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(&allproc);
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 = 0xf8009d7

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, &error)) {
679 bo = &ap->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 panic with "vi

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

[Fabian Keil]

Konstantin Belousov  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

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

[Fabian Keil]

Konstantin Belousov  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  wrote:

> Xin Li  wrote:
> 
> > On 9/7/14 11:23 PM, Fabian Keil wrote:  
> > > Xin Li  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 in sleepq_wait (wchan=0x0, pri=0) at 
/usr/src/sy

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

[Fabian Keil]

Xin Li  wrote:

> On 9/7/14 11:23 PM, Fabian Keil wrote:
> > Xin Li  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  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  wrote:

> On Fri, Aug 28, 2015 at 4:18 AM,  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  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 "r"untime 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"  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  wrote:

> On Sat, 30 May 2015 05:52:56 -0400
> Aryeh Friedman  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"  wrote:

> On Tue, Apr 07, 2015 at 13:16:04 +0200, Fabian Keil wrote:
> > "Kenneth D. Merry"  wrote:
> > 
> > > On Mon, Apr 06, 2015 at 15:39:56 +0200, Fabian Keil wrote:
> > > > "Kenneth D. Merry"  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"  wrote:

> On Mon, Apr 06, 2015 at 15:39:56 +0200, Fabian Keil wrote:
> > "Kenneth D. Merry"  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"  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  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
> >  wrote:
> > > John-Mark Gurney  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  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=, 
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=, 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=) at /usr/src/sys/amd64/amd64/trap.c:856
#7  0x8088a131 in trap_pfault (frame=0xfe009397b7e0, 
usermode=) 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 , 
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
#25 0x81a3aa4f in pool_status_check (name=0xfe0003232000 "tank", 
type=DATASET_NAME, check

Re: Devops question: unattended installs of FreeBSD?

[Fabian Keil]

Jamie Landeg-Jones  wrote:

> Craig Rodrigues  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  wrote:

> Hans Petter Selasky  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=, flags=) at /usr/src/sys/kern/sched_ule.c:1940
1940cpuid = PCPU_GET(cpuid);
(kgdb) where
#0  sched_switch (td=0xf8001d2044a0, newtd=, 
flags=) 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=, lock=, priority=, wmesg=, 
sbt=, pr=, 
flags=) at /usr/src/sys/kern/kern_synch.c:250
#4  0x805bbe10 in pause_sbt (wmesg=, sbt=, pr=0, flags=) at 
/usr/src/sys/kern/kern_synch.c:379
#5  0x81e2f175 in usb_pause_mtx (mtx=, timo=) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_util.c:143
#6  0x81e16ed7 in usb_ioctl (dev=, cmd=, addr=, fflag=0, td=)
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=, td=0xf8001d2044a0) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:775
#8  0x8061041e in kern_ioctl (td=0xf8001d2044a0, fd=, 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=, flags=) at /usr/src/sys/kern/sched_ule.c:1940
1940cpuid = PCPU_GET(cpuid);
(kgdb) where
#0  sched_switch (td=0xf8001d3a5940, newtd=, 
flags=) 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=, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:688
#4  0x805ba6ad in _sx_xlock (sx=0x0, opts=0, file=, 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=0xf80015b518c0, 
crd=0xfe009453f630, need_uref=) at 
/usr/src/sys/modules/usb/usb/../../../dev/usb/usb_dev.c:231
#7  0x81e15caf in usb_open (dev=, fflags=3, 
devtype=, td=0x0) at 
/usr/src/sys/modules/usb/usb/../../../dev/usb/usb_dev.c:887
#8  0x8047ae52

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  wrote:

> On 11/06/2014 12:30, Fabian Keil wrote:
> > Eric van Gyzen  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  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: Order of geli "passphrase prompt" on boot

[Fabian Keil]

Kurt Jaeger  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: Order of geli "passphrase prompt" on boot

[Fabian Keil]

Miguel Clara  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: CTF: geom gate network patch

[Fabian Keil]

John-Mark Gurney  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: Panic after USB deadlock followed by kldunload umass.ko

[Fabian Keil]

Hans Petter Selasky  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

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

[Fabian Keil]

Xin Li  wrote:

> On 9/7/14 11:23 PM, Fabian Keil wrote:
> > Xin Li  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

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

[Fabian Keil]

Xin Li  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=, 
flags=) 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=) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zio.c:1442
#5  0x81102111 in dbuf_read (db=, zio=, flags=) at 
/usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/dbuf.c:649
#6  0x81108e6d in dmu_buf_hold (os=, object=, offset=, tag=0x0, dbp=0xfe00955c6648, 
flags=)
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=)
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  to continue, or q  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=, zcmd=, arg=, flag=, 
td=)
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=, td=0xf800628cc490) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:757
#14 0x805f3c3d in kern_ioctl (td=0xf800628cc490, fd=, 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=, 
flags=) 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=, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:676
#4  0x805a0add in _sx_xlock (sx=0x0, opts=0, file=, 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 in zfsdev_ioctl (dev=, zcmd=, arg=, flag=, 
td=)
at /usr/src/sys/cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_ioctl.c:6136
#9  0x80464a55 in devfs_ioctl_f (fp=0xf8000631a320, com=3222821381, 
data=0xf800067b8d00, cred=, td=0xf80015a63920) at 
/usr/src/sys/fs/devfs/devfs_vno

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=) 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 , 
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=, flags=) at /usr/src/sys/kern/sched_ule.c:1932
1932cpuid = PCPU_GET(cpuid);
(kgdb) bt
#0  sched_switch (td=0xf80015289490, newtd=, 
flags=) 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=, file=0x0, line=0) at 
/usr/src/sys/kern/kern_sx.c:676
#4  0x805a0add in _sx_xlock (sx=0x0, opts=0, file=, 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=, zcmd=, arg=, flag=, 
td=)
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=, td=0xf80015289490) at 
/usr/src/sys/fs/devfs/devfs_vnops.c:757
#10 0x805f3c3d in kern_ioctl (td=0xf80015289490, fd=, 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=, 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: http://illumos.org/msg/ZFS-8000-9P
  scan: scrub repaired 2.98M in 16h27m with 0 errors on Sun Sep  7 12:25:36 2014
config:

NAME   STATE READ WRITE CKSUM
spaceloop  ONLINE   0 0 0
  label/spaceloop.eli  ONLINE   0 026

errors: N

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

[Fabian Keil]

Trond Endrestøl  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=, s2=, n=) 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=) at 
> > /usr/src/lib/libc/stdlib/getenv.c:144
> > #2  __findenv_environ (name=, nameLen=) 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=, s2=, 
> > n=) at /usr/src/lib/libc/string/strncmp.c:46
> > #1  0x00080128bb92 in getenv (name=) 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  > 0x22313031734e6863 out of bounds>, t=0x8012a009e, pt=0x2  > of bounds>, ptlim=0xf5 , 
> > warnp=0x8014cc418 , loc=0x80126bb1b ) at 
> > /usr/src/lib/libc/stdtime/strftime.c:137
> > #5  0x00080122d6fb in _conv (n=, format=, 
> > pt=, n=, format=, 
> > pt=, ptlim=)
> > at /usr/src/lib/libc/stdtime/strftime.c:597
> > #6  _yconv (a=, b=, convert_top= > out>, convert_yy=, pt=, ptlim= > out>, a=, b=, 
> > convert_top=, convert_yy=, pt= > out>, ptlim=) 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

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=, s2=, n=) 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=) at 
/usr/src/lib/libc/stdlib/getenv.c:144
#2  __findenv_environ (name=, nameLen=) 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=, s2=, 
n=) at /usr/src/lib/libc/string/strncmp.c:46
#1  0x00080128bb92 in getenv (name=) 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 , t=0x8012a009e, pt=0x2 , ptlim=0xf5 , 
warnp=0x8014cc418 , loc=0x80126bb1b ) at 
/usr/src/lib/libc/stdtime/strftime.c:137
#5  0x00080122d6fb in _conv (n=, format=, 
pt=, n=, format=, pt=, ptlim=)
at /usr/src/lib/libc/stdtime/strftime.c:597
#6  _yconv (a=, b=, convert_top=, 
convert_yy=, pt=, ptlim=, 
a=, b=, 
convert_top=, convert_yy=, pt=, ptlim=) 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 believe this happened as a result of a stack
==6563==  overflow in your program's main thread (unlikely but
==6563==  possible), you can try to increase the size of the
==6563==  main thread stack using the --main-stacksize= flag.
==6563==  The main thread stack size used in this run was 16777216.
==6563== 
==6563== HEAP SUMMARY:
==6563== in use at exit: 18,848 bytes in 6 blocks
==6563==   total heap usage: 25 allocs, 19 frees, 47,144 bytes allocated
==6563== 
==6563== LEAK

Re: Ordering for network-sensitive rc scripts

[Fabian Keil]

David Chisnall  wrote:

> On 11 May 2014, at 20:23, Adrian Chadd  wrote:
> 
> > On 11 May 2014 12:01, David Chisnall  wrote:
> >> On 17 Apr 2014, at 09:30, Adrian Chadd  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 [SOLVED]

[Fabian Keil]

"Steven Hartland"  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

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

[Fabian Keil]

"Steven Hartland"  wrote:

> > "Steven Hartland"  wrote:
> > 
> > > From: "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.
> > > >
> > > 
> > > 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=dmesgd&do=view&dmesgid=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

[Fabian Keil]

"Steven Hartland"  wrote:

> From: "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.
> >
> 
> 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=dmesgd&do=view&dmesgid=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

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: claws-mail deadlocking in iconv

[Fabian Keil]

Fabian Keil  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=) at /usr/src/lib/libthr/thread/thr_umtx.c:296
#2  0x000808489b1d in rwlock_wrlock_common (rwlock=, 
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=) 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=) 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=, 
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=) 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=) 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 
/usr/src/lib/libc/iconv/citrus_iconv.c:335
#11 0x0008090f2ca6 in iconv_close (handle=0x80a8ede20) at 
/usr/src/lib/libc/iconv/iconv.c:131
#12 0x0046

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

[Fabian Keil]

Alexander Motin  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  wrote:

> On 12.07.2013 12:56, Fabian Keil wrote:
> > Andre Oppermann  wrote:
> >
> >> On 10.07.2013 15:18, Fabian Keil wrote:
> >>> Andre Oppermann  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  wrote:

> On 10.07.2013 15:18, Fabian Keil wrote:
> > Andre Oppermann  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 0x18; 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 0x11; 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 

Re: Improved SYN Cookies: Looking for testers

[Fabian Keil]

Andre Oppermann  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

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  wrote:

> on 01/04/2013 17:18 Fabian Keil said the following:
> > #10 0x8130323f in assfail3 (a=, lv= > optimized out>, op=, rv=, 
> > f=, l=)
> > at 
> > /usr/src/sys/modules/opensolaris/../../cddl/compat/opensolaris/kern/opensolaris_cmn_err.c:89
> > #11 0x8117924e in zfs_space_delta_cb (bonustype= > 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=) 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=, tx=)
> > 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=, 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= > 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 
> > , 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=) 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 
, 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, 

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=, dummy2=0, 
dummy3=0, dummy4=0x0) at /usr/src/sys/ddb/db_command.c:543
#2  0x80319eca in db_command (last_cmdp=, 
cmd_table=, 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=, code=0) at 
/usr/src/sys/ddb/db_main.c:231
#5  0x805d0da3 in kdb_trap (type=3, code=0, tf=) 
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=) at cpufunc.h:63
#9  0x80599216 in panic (fmt=) at 
/usr/src/sys/kern/kern_shutdown.c:747
#10 0x8130323f in assfail3 (a=, lv=, op=, rv=, f=, l=)
at 
/usr/src/sys/modules/opensolaris/../../cddl/compat/opensolaris/kern/opensolaris_cmn_err.c:89
#11 0x8117924e in zfs_space_delta_cb (bonustype=, 
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=) 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=, tx=)
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=, 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=) 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 
, 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=) 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 = 0x811da0bf "dn->dn_mtx", lo_flags = 4096, lo_data = 
0, lo_witness = 0x0}, sx_lock = 1}, dn_dirty_records = {{list_size = 208, 
list_offset = 0, list_head = {
list_next = 0xfe004261c470, list_prev = 0xfe004261c470}}, 
{list_size = 208, list_offset = 0, list_head = {list_next = 0xfe004261c490, 
list_prev = 0xfe004261c490}}, {list_size = 208, 
  

Re: 7+ days of dogfood

[Fabian Keil]

Glen Barber  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: 7+ days of dogfood

[Fabian Keil]

David Chisnall  wrote:

> On 11 Feb 2013, at 13:56, Fabian Keil 
> 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]

David Chisnall  wrote:

> On 11 Feb 2013, at 10:48, Fabian Keil 
> 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]

Erich Dollansky  wrote:

> On Mon, 11 Feb 2013 11:48:11 +0100
> Fabian Keil  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]

Steve Kargl  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: geli(8) breaks after a couple hours of uptime

[Fabian Keil]

Pawel Jakub Dawidek  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

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: Physbio changes final call for tests and reviews

[Fabian Keil]

Konstantin Belousov  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

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

[Fabian Keil]

Eitan Adler  wrote:

> On 8 February 2013 07:46, Andriy Gapon  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: geli(8) breaks after a couple hours of uptime

[Fabian Keil]

Ulrich Spörlein  wrote:

> On Thu, 2013-02-07 at 15:33:22 +0100, Fabian Keil wrote:
> > Ulrich Spörlein  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  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  wrote:

> In the last episode (Jan 28), Fabian Keil said:
> > Ulrich Spörlein  wrote:
> > > On Mon, 2013-01-28 at 07:11:40 +1100, Peter Jeremy wrote:
> > > > On 2013-Jan-27 14:31:56 -, Steven Hartland 
> > > >  wrote:
> > > > >- Original Message - 
> > > > >From: "Ulrich Spörlein" 
> > > > >> 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  wrote:

> On Mon, 2013-01-28 at 07:11:40 +1100, Peter Jeremy wrote:
> > On 2013-Jan-27 14:31:56 -, Steven Hartland  
> > wrote:
> > >- Original Message - 
> > >From: "Ulrich Spörlein" 
> > >> 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  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  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  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  wrote:

> On Fri, Jan 4, 2013 at 10:28 AM, Fabian Keil
>  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: ZFS/RAIDZ and SAMBA: abyssimal performance

[Fabian Keil]

Fleuriot Damien  wrote:

> 
> On Jan 4, 2013, at 4:19 PM, O. Hartmann  wrote:
> 
> > Am 01/04/13 15:45, schrieb Garrett Cooper:
> >> On Fri, Jan 4, 2013 at 6:06 AM, Fleuriot Damien  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: Unbreaking gdb's catch throw

[Fabian Keil]

Stefan Farfeleder  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: [RFC/RFT] calloutng

[Fabian Keil]

Fabian Keil  wrote:

> Alexander Motin  wrote:
> 
> > On 20.12.2012 15:26, Fabian Keil wrote:
> > > Alexander Motin  wrote:
> > >
> > >> On 20.12.2012 12:56, Fabian Keil wrote:
> > >>> Alexander Motin  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  wrote:

> On 20.12.2012 15:26, Fabian Keil wrote:
> > Alexander Motin  wrote:
> >
> >> On 20.12.2012 12:56, Fabian Keil wrote:
> >>> Alexander Motin  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

Re: [RFC/RFT] calloutng

[Fabian Keil]

Alexander Motin  wrote:

> On 20.12.2012 12:56, Fabian Keil wrote:
> > Alexander Motin  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  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

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  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"  wrote:

> On Tue, Aug 21, 2012 at 1:05 PM, Ulrich Spörlein  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  | 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  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  wrote:

> --- Mar 26/6/12, Mark Peek  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  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  wrote:

> Hello Fabian;
> 
> --- Sab 23/6/12, Fabian Keil ha scritto:
> 
> > Pedro Giffuni  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: [RFT] llquantize for FreeBSD's dtrace

[Fabian Keil]

Pedro Giffuni  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 
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:
...
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=, 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=, file=, 
expr=) 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=, 
cnp=, dtp=)
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=, spec=DTRACE_PROBESPEC_PROVIDER, cflags=0, argc=-2123430480, 
argv=)
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=, argv=0x7fffd668) at 
/usr/src/cddl/usr.sbin/dtrace/../../../cddl/contrib/opensolaris/cmd/dtrace/dtrace.c:1632

Fabian


signature.asc
Description: PGP signature

Re: DTrace broken on 9.0-Release?

[Fabian Keil]

Ryan Goodfellow  wrote:

> Today I downloaded and installed FreeBSD 9.0-RELEASE and followed the
> directions from  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
> #include
> 
> 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  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  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 
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  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  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 Belousov  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:
> >>>>>>> spinlock_exit ->  critical_exit ->  mi_switch ->  kdb_switch 
> >>>>>>> ->
> >>>>>>> thread_unlock ->  spinlock_exit ->  critical_exit ->  mi_switch ->  
> >>>>>>> ...
> >>>>>>> in the kdb context
> >>>>>>> this issue seems to be triggered by td_owepreempt being true 
> >>>>>>> at 
> >>>>>>> the time
> >>>>>>> kdb is entered
> >>>>>>> and there of course has to be an initial spinlock_exit call 
> >>>>>>> somewhere
> >>>>>>> in my case it's because of usb keyboard
> >>>>>>> I wonder if it would make sense to clear td_owepreempt right 
> >>>>>>> before
> >>>>>>> calling kdb_switch in mi_switch
> >>>>>>> instead of in sched_switch()
> >>>>>>> clearing td_owepreempt seems like a scheduler-independent 
> >>>>>>> operation to me
> >>>>>>> or is it better to just skip locking in usb when kdb_active 
> >>>>>>> is set
> >>>>>>> ?
> >>>>>>>
> >>>>>>> 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  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  wrote:

> Fabian Keil  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  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:  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

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

[Fabian Keil]

George Neville-Neil  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