From mboxrd@z Thu Jan 1 00:00:00 1970 From: Jeff Layton Subject: Re: [PATCH] audit: grab a reference to context->pwd when it's cached Date: Mon, 8 Oct 2012 08:23:19 -0400 Message-ID: <20121008082319.5ecf3677@tlielax.poochiereds.net> References: <1345079613-27388-1-git-send-email-pmoody@google.com> <20120926135020.GB31705@shell.devel.redhat.com> <20121005085558.76d36641@corrin.poochiereds.net> <20121005102604.6eccd676@corrin.poochiereds.net> <20121005121527.4b425686@corrin.poochiereds.net> Mime-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Return-path: In-Reply-To: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: linux-audit-bounces@redhat.com Errors-To: linux-audit-bounces@redhat.com To: Peter Moody Cc: lczerner@redhat.com, linux-audit@redhat.com, sandeen@redhat.com List-Id: linux-audit@redhat.com On Fri, 5 Oct 2012 12:41:46 -0700 Peter Moody wrote: > On Fri, Oct 5, 2012 at 10:04 AM, Peter Moody wrote: > > On Fri, Oct 5, 2012 at 9:15 AM, Jeff Layton wrote: > > > >>> > >>> ------------[ cut here ]------------ > >>> kernel BUG at fs/buffer.c:1220! > >>> invalid opcode: 0000 [#1] SMP > >>> CPU 0 > >>> Pid: 3683, comm: a.out Not tainted 3.5.0 #3 > >>> RIP: e030:[] [] > >>> check_irqs_on.part.8+0x4/0x6 > >>> RSP: e02b:ffff8807b156dc28 EFLAGS: 00010046 > >>> RAX: ffff8807d0dd0000 RBX: ffff8807a7d6df28 RCX: 0000000005883396 > >>> RDX: 0000000000001000 RSI: 0000000005883396 RDI: ffff8807cfc0c000 > >>> RBP: ffff8807b156dc28 R08: 0000000000000001 R09: ffff8807a7d6de50 > >>> R10: f83a2b0a359bf007 R11: 0000000000000000 R12: ffff8807a7d6de54 > >>> R13: ffff8807a7d6de80 R14: ffff8807cfc1f120 R15: 0000000005883396 > >>> FS: 00007f97164ec700(0000) GS:ffff8807ffc00000(0063) knlGS:0000000000000000 > >>> CS: e033 DS: 002b ES: 002b CR0: 000000008005003b > >>> CR2: 00000000f76ca3b0 CR3: 00000007bbb53000 CR4: 0000000000002660 > >>> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > >>> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 > >>> Process a.out (pid: 3683, threadinfo ffff8807b156c000, task ffff8807bbae8000) > >>> Stack: > >>> ffff8807b156dc98 ffffffff8116a099 ffff8807b59f3000 ffff8807b156dd30 > >>> ffff8807b156dd60 ffff8807b156de78 ffff8807b156dc78 ffffffff816af231 > >>> ffff8807b156dcd8 ffff8807a7d6e538 ffff8807a7d6df28 ffff8807a7d6de54 > >>> Call Trace: > >>> [] __find_get_block+0x1f9/0x200 > >>> [] ? down_read+0x11/0x30 > >>> [] ext3_clear_blocks+0x75/0x140 > >>> [] ext3_free_data+0x10c/0x150 > >>> [] ? ext3_journal_start_sb+0x31/0x60 > >>> [] ext3_truncate+0x4a5/0x600 > >>> [] ? journal_start+0xb8/0x100 > >>> [] ? bit_waitqueue+0x16/0xc0 > >>> [] ext3_evict_inode+0x248/0x2c0 > >>> [] evict+0xaa/0x1b0 > >>> [] iput+0x103/0x210 > >>> [] dentry_iput+0x88/0xd0 > >>> [] dput+0x12c/0x250 > >>> [] path_put+0x15/0x30 > >>> [] __audit_syscall_exit+0x2e5/0x460 > >>> [] sysexit_audit+0x29/0x5b > >>> Code: 04 00 00 4c 8d 88 c0 02 00 00 31 c0 e8 5f da ff ff 48 85 db 74 > >>> 0c 80 43 5c 01 48 89 df e8 d5 > >>> 6a aa ff 5b 41 5c 5d c3 55 48 89 e5 <0f> 0b 55 48 89 e5 0f 0b 55 48 89 > >>> e5 0f 0b 55 48 89 e5 41 54 53 > >>> RIP [] check_irqs_on.part.8+0x4/0x6 > >>> RSP > >>> ---[ end trace 8d09f8cfbb601c14 ]--- > >>> > >>> > >> > >> I don't see a function called sysexit_audit in 3.5. I assume that's > >> created via some sort of macro goop? > > > > It looks like it's defined in arch/x86/kernel/entry_32.S > > > > my asm is non-existent, but it looks like it's calling > > __audit_syscall_exit and the disabling interrupts. > > > >> Could this be a xen specific problem? > > > > It could be. I asked the xen folks about this and they felt that it > > was unlikely that the bug itself was their > > (http://lists.xen.org/archives/html/xen-devel/2012-08/msg01052.html, > > specifically http://lists.xen.org/archives/html/xen-devel/2012-08/msg01127.html) > > > > xen could definitely be doing something wonky with irqs though. > > > >> Might be interesting to add a > >> check for irqs being disabled early in __audit_syscall_exit and see > >> whether its doing that universally in its syscall exit routine? > > > > I'll try this, thanks. > > So, I've added WARN_ON(irqs_disabled()) in various spots in the > audit_syscall_exit path all the way up to the path_put in > audit_free_names() that ends up triggering this and prior to Oops'ing, > I don't see anything. > > Post oops, I get lots of messages like: > > ------------[ cut here ]------------ > WARNING: at kernel/auditsc.c:1021 audit_free_names+0xb0/0xdb() > Pid: 3981, comm: python2.6 Tainted: G D W 3.2.5-at17-ganetixenu #31 > Call Trace: > [] ? audit_free_names+0xb0/0xdb > [] warn_slowpath_common+0x75/0xb0 > [] warn_slowpath_null+0x15/0x20 > [] audit_free_names+0xb0/0xdb > [] audit_syscall_exit+0x139/0x1e0 > [] sysexit_audit+0x21/0x5f > ---[ end trace ec7a15dbe40eaf1d ]--- > ------------[ cut here ]------------ > WARNING: at kernel/auditsc.c:1021 audit_free_names+0xb0/0xdb() > Pid: 3981, comm: python2.6 Tainted: G D W 3.2.5-at17-ganetixenu #31 > Call Trace: > [] ? audit_free_names+0xb0/0xdb > [] warn_slowpath_common+0x75/0xb0 > [] warn_slowpath_null+0x15/0x20 > [] audit_free_names+0xb0/0xdb > [] audit_syscall_exit+0x139/0x1e0 > [] sysexit_audit+0x21/0x5f > ---[ end trace ec7a15dbe40eaf1e ]--- > > where that python command is a python par file that may be doing some > funny unlinking as well. I haven't tracked it down. > > thoughts? does this not look like a bug in audit; maybe something > somewhere else is disabling interrupts? > I'm not sure whether it's a bug in audit or not. Tracking down what's disabling interrupts here is probably the key though... So I'm guessing the WARN_ON above was in audit_free_names. Was there a similar WARN_ON in audit_syscall_exit that did not fire? -- Jeff Layton