From owner-freebsd-stable@FreeBSD.ORG Thu Jul 4 06:16:00 2013 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) by hub.freebsd.org (Postfix) with ESMTP id 59BEE239; Thu, 4 Jul 2013 06:16:00 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from kib.kiev.ua (kib.kiev.ua [IPv6:2001:470:d5e7:1::1]) by mx1.freebsd.org (Postfix) with ESMTP id A74B2105B; Thu, 4 Jul 2013 06:15:59 +0000 (UTC) Received: from tom.home (kostik@localhost [127.0.0.1]) by kib.kiev.ua (8.14.7/8.14.7) with ESMTP id r646Foot060469; Thu, 4 Jul 2013 09:15:50 +0300 (EEST) (envelope-from kostikbel@gmail.com) DKIM-Filter: OpenDKIM Filter v2.8.3 kib.kiev.ua r646Foot060469 Received: (from kostik@localhost) by tom.home (8.14.7/8.14.7/Submit) id r646FoQv060467; Thu, 4 Jul 2013 09:15:50 +0300 (EEST) (envelope-from kostikbel@gmail.com) X-Authentication-Warning: tom.home: kostik set sender to kostikbel@gmail.com using -f Date: Thu, 4 Jul 2013 09:15:50 +0300 From: Konstantin Belousov To: Andre Albsmeier Subject: Re: FreeBSD-9.1: machine reboots during snapshot creation, LORs found Message-ID: <20130704061550.GI91021@kib.kiev.ua> References: <20130531122611.GA6607@bali> <201305311051.03157.jhb@freebsd.org> <20130616063942.GA72803@bali> <201306171530.31208.jhb@freebsd.org> <20130704051409.GA22021@bali> <20130704052440.GG91021@kib.kiev.ua> <20130704052659.GA23398@bali> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="Q1ykKx60OEcPG/sP" Content-Disposition: inline In-Reply-To: <20130704052659.GA23398@bali> User-Agent: Mutt/1.5.21 (2010-09-15) X-Spam-Status: No, score=-2.0 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_ADSP_CUSTOM_MED,FREEMAIL_FROM,NML_ADSP_CUSTOM_MED autolearn=no version=3.3.2 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on tom.home Cc: "freebsd-stable@freebsd.org" , John Baldwin X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 04 Jul 2013 06:16:00 -0000 --Q1ykKx60OEcPG/sP Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable On Thu, Jul 04, 2013 at 07:27:00AM +0200, Andre Albsmeier wrote: > On Thu, 04-Jul-2013 at 07:24:40 +0200, Konstantin Belousov wrote: > > On Thu, Jul 04, 2013 at 07:14:09AM +0200, Andre Albsmeier wrote: > > > On Mon, 17-Jun-2013 at 21:30:31 +0200, John Baldwin wrote: > > > > On Sunday, June 16, 2013 2:39:42 am Andre Albsmeier wrote: > > > > > On Fri, 31-May-2013 at 16:51:03 +0200, John Baldwin wrote: > > > > > > On Friday, May 31, 2013 8:26:11 am Andre Albsmeier wrote: > > > > > > > Each day at 5:15 we are generating snapshots on various machi= nes. > > > > > > > This used to work perfectly under 7-STABLE for years but since > > > > > > > we started to use 9.1-STABLE the machine reboots in about 10% > > > > > > > of all cases. > > > > > > >=20 > > > > > > > After rebooting we find a new snapshot file which is a bit > > > > > > > smaller than the good ones and with different permissions > > > > > > > It does not succeed a fsck. In this example it is the one > > > > > > > whose name is beginning with s3: > > > > > > >=20 > > > > > > > -r--r----- 1 root operator snapshot 72802894528 29 May 05= :15 s2-2013.05.28-03.15.04 > > > > > > > -r-------- 1 root operator snapshot 72802893824 29 May 05= :15 s3-2013.05.29-03.15.03 > > > > > > > -r--r----- 1 root operator snapshot 72802894528 28 May 14= :22 s4-2013.05.23-06.38.44 > > > > > > > -r--r----- 1 root operator snapshot 72802894528 28 May 14= :22 s5-2013.05.24-03.15.03 > > > > > > > -r--r----- 1 root operator snapshot 72802894528 28 May 14= :22 s6-2013.05.25-03.15.03 > > > > > > >=20 > > > > > > > After enabling DIAGNOSTIC, WITNESS and INVARIANTS in the kern= el > > > > > > > I see the following LORs (mksnap_ffs starts exactly at 5:15): > > > > > > >=20 > > > > > > > May 29 05:15:00 palveli kernel: lock order revers= al: > > > > > > > May 29 05:15:00 palveli kernel: 1st 0xc2371da8 uf= s (ufs) @ /src/src-9/sys/kern/vfs_mount.c:1240 > > > > > > > May 29 05:15:00 palveli kernel: 2nd 0xc2371ec4 de= vfs (devfs) @ /src/src-9/sys/ufs/ffs/ffs_vfsops.c:1414 > > > > > > > May 29 05:15:04 palveli kernel: lock order revers= al: > > > > > > > May 29 05:15:04 palveli kernel: 1st 0xc228471c sn= aplk (snaplk) @ /src/src-9/sys/ufs/ufs/ufs_vnops.c:976 > > > > > > > May 29 05:15:04 palveli kernel: 2nd 0xc22f25e4 uf= s (ufs) @ /src/src-9/sys/ufs/ffs/ffs_snapshot.c:1626 > > > > > > >=20 > > > > > > > Unfortunatley no corefiles are being generated ;-(. > > > > > > >=20 > > > > > > > I have checked and even rebuilt the (UFS1) fs in question > > > > > > > from scratch. I have also seen this happen on an UFS2 on > > > > > > > another machine and on a third one when running "dump -L" > > > > > > > on a root fs. > > > > > > >=20 > > > > > > > Any hints of how to proceed? > > > > > >=20 > > > > > > Would it be possible to setup a serial console that is logged o= n this machine > > > > > > to see if it is panic'ing but failing to write out a crashdump? > > > > >=20 > > > > > Couldn't attach the serial console yet ;-(. But I had people > > > > > attach a KVMoverIP switch and enabled the various KDB options > > > > > in the kernel. Now we can see a bit more (see below) -- no > > > > > crashdump is being generated though. > > > >=20 > > > > :( Unfortunately these LORs don't really help with discerning the = cause of > > > > the reboot. If you have remote power access (and still wanted to t= est this) > > > > one option would be to change KDB to drop into the debugger on a pa= nic. > > > > Then you could connect over the KVM and take images of the original= panic > > > > along with a stack trace. > > >=20 > > > After a few days of no problems, the box decided to crash > > > during mksnap_ffs today ;-(. But now I have a crashdump, > > > see below. Unfortunatley, I cannot upload the dump somewhere > > > but if you ask me check whatever things I'll be happy to help. > > >=20 > > > kgdb /usr/obj/src/src-9/sys/palveli/kernel.debug vmcore.4 > > > 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 con= ditions. > > > Type "show copying" to see the conditions. > > > There is absolutely no warranty for GDB. Type "show warranty" for de= tails. > > > This GDB was configured as "i386-marcel-freebsd"... > > >=20 > > > Unread portion of the kernel message buffer: > > >=20 > > >=20 > > > Fatal trap 12: page fault while in kernel mode > > > fault virtual address =3D 0xcfb5e000 > > > fault code =3D supervisor write, page not present > > > instruction pointer =3D 0x20:0xc07cb2fe > > > stack pointer =3D 0x28:0xd83545d0 > > > frame pointer =3D 0x28:0xd835490c > > > code segment =3D base 0x0, limit 0xfffff, type 0x1b > > > =3D DPL 0, pres 1, def32 1, gran 1 > > > processor eflags =3D interrupt enabled, resume, IOPL =3D 0 > > > current process =3D 12929 (mksnap_ffs) > > > trap number =3D 12 > > > panic: page fault > > > KDB: stack backtrace: > > > db_trace_self_wrapper(c08207eb,d835441c,c05fdfc9,c081df13,c08a82e0,..= =2E) at db_trace_self_wrapper+0x26/frame 0xd83543ec > > > kdb_backtrace(c081df13,c08a82e0,c0801bfa,d8354428,d8354428,...) at kd= b_backtrace+0x29/frame 0xd83543f8 > > > panic(c0801bfa,c0845a01,c2bafae4,1,1,...) at panic+0xc9/frame 0xd8354= 41c > > > trap_fatal(c0ff6000,cfb5e000,2,0,265abf,...) at trap_fatal+0x353/fram= e 0xd835445c > > > trap_pfault(140da,0,c2baf930,c08b6a40,c282145c,...) at trap_pfault+0x= 2d7/frame 0xd83544a4 > > > trap(d8354590) at trap+0x41a/frame 0xd8354584 > > > calltrap() at calltrap+0x6/frame 0xd8354584 > > > --- trap 0xc, eip =3D 0xc07cb2fe, esp =3D 0xd83545d0, ebp =3D 0xd8354= 90c --- > > > bcopy(c2b36548,c2f194e0,0,0,0,...) at bcopy+0x1a/frame 0xd835490c > > > ffs_mount(c2b36548,c2db9000,ff,d8354c08,c2b665e4,...) at ffs_mount+0x= 15ee/frame 0xd8354a3c > >=20 > > From the crash dump in kgdb, do > > list *ffs_mount+0x15ee >=20 > (kgdb) list *ffs_mount+0x15ee > 0xc0748e8e is in ffs_mount (/src/src-9/sys/ufs/ffs/ffs_vfsops.c:483). > 478 > 479 /* > 480 * If this is a snapshot request, take the snapsh= ot. > 481 */ > 482 if (mp->mnt_flag & MNT_SNAPSHOT) > 483 return (ffs_snapshot(mp, fspec)); > 484 } > 485 > 486 /* > 487 * Not an update, or updating the name: look up the name It is not useful, bcopy does not create a frame, so the real caller of the failing bcopy gets lost. It could be uncovered with some stack digging, but I believe it would be easier just fix bcopy. Please apply this patch and reproduce the panic again, then the kgdb backtrace should be more useful. diff --git a/sys/i386/i386/support.s b/sys/i386/i386/support.s index 967a09e..779fa38 100644 --- a/sys/i386/i386/support.s +++ b/sys/i386/i386/support.s @@ -181,11 +181,13 @@ END(bcopyb) * ws@tools.de (Wolfgang Solfrank, TooLs GmbH) +49-228-985800 */ ENTRY(bcopy) + pushl %ebp + movl %esp,%ebp pushl %esi pushl %edi - movl 12(%esp),%esi - movl 16(%esp),%edi - movl 20(%esp),%ecx + movl 8(%ebp),%esi + movl 12(%ebp),%edi + movl 16(%ebp),%ecx =20 movl %edi,%eax subl %esi,%eax @@ -196,12 +198,13 @@ ENTRY(bcopy) cld /* nope, copy forwards */ rep movsl - movl 20(%esp),%ecx + movl 16(%ebp),%ecx andl $3,%ecx /* any bytes left? */ rep movsb popl %edi popl %esi + popl %ebp ret =20 ALIGN_TEXT @@ -214,7 +217,7 @@ ENTRY(bcopy) std rep movsb - movl 20(%esp),%ecx /* copy remainder by 32-bit words */ + movl 16(%ebp),%ecx /* copy remainder by 32-bit words */ shrl $2,%ecx subl $3,%esi subl $3,%edi @@ -223,6 +226,7 @@ ENTRY(bcopy) popl %edi popl %esi cld + popl %ebp ret END(bcopy) =20 --Q1ykKx60OEcPG/sP Content-Type: application/pgp-signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.20 (FreeBSD) iQIcBAEBAgAGBQJR1RMVAAoJEJDCuSvBvK1B8AoQAJFjo/vCKR561LcJcSqI9UFf nwsWeOPOa6uXNoTQrV4S+vC2PDiT4MRLbSOIrT+gEVpnSg8W62Z1lSQBb+/VsrSS OYAhbPjsrtmMSS1Lk2A/3Crq9E05Oiq9hl9EVgvtlMKZRabckHAc/3pKmrzsnxUg Ft56OCEQiK0pI1czbglb3PGMP0vrHXi1OimQ+P5LKZCnmykuHEdKw3vdfZ2Fz9BO Vwbs8P4CJRMV5OKu/hlA5teZ1JrI/7XihGSYxlQ6csoa8I5NtWHf38h8Di7FbtwI vh8NEVnHzNc6W+mBFJjMl8Wi0oFsH1iJQxVas0tHQuguIA8EKi/6CxAhViFL44Qe 04jNXZJDf5uJLeUmor2Vce7ytNp7uY2ZhtgEgCTHZeyuayJ09tzXIj+GYeRx1O9Z KcEfxhPDSQI3IFAU+Ep9ibqgBVjLBiLhjesPbrg58W2/OIakvoSJcAWNUwfYHh9u 3sdhSfnrjfGULXvKK9VuWQX1dqGyPf7VVGZ+4lBjBwWbp3ziGAHqbpmGzLqXU54/ 4pMHIT2vdK1/40pbqHW2S8k3lg8qmB4PnqGN5UtrMEwqu82hXflpEuVEbr2YWgXp H+SjJUXm6ZZkhz6dRcSXrsppeXpsnxzipyX5tOZk+EuacVPiQ2xqlGSD5wmXU6Jo lOUP7CCWcrjgWSnr4Pgp =O1v/ -----END PGP SIGNATURE----- --Q1ykKx60OEcPG/sP--