Bug 519737

Summary:	continues oops in the kernel ima_file_free
Product:	[Fedora] Fedora	Reporter:	Sachin Garg <ascii79>
Component:	kernel	Assignee:	Eric Paris <eparis>
Status:	CLOSED UPSTREAM	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	medium	Docs Contact:
Priority:	low
Version:	12	CC:	cristian.ciupitu, fche, igeorgex, itamar, kernel-maint, mjw
Target Milestone:	---	Keywords:	Triaged
Target Release:	---
Hardware:	All
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2010-02-05 21:30:48 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Sachin Garg 2009-08-27 15:47:47 UTC

Description of problem:

Aug 27 10:46:45 office103-148 kernel: ima_file_free: ECRYPTFS_FNEK_ENCRYPTED.FXasX-EnNvCx1ERRuiGMxgWGGqbfDj8EiBu4bI8PJRTkPcoXiXpE2NKPCQZysHZJ563BdZLvl3NozXY- open/free imbalance (r:0 w:0 o:0 f:0)
Aug 27 10:46:45 office103-148 kernel: Pid: 1720, comm: firefox Not tainted 2.6.31-0.180.rc7.git4.fc12.i686 #1
Aug 27 10:46:45 office103-148 kernel: Call Trace:
Aug 27 10:46:45 office103-148 kernel: [<c05d2795>] ima_file_free+0x95/0xfd
Aug 27 10:46:45 office103-148 kernel: [<c04fa3b0>] __fput+0x10f/0x1a9
Aug 27 10:46:45 office103-148 kernel: [<c04fa471>] fput+0x27/0x3a
Aug 27 10:46:45 office103-148 kernel: [<fd602c55>] ecryptfs_destroy_inode+0x4a/0xd8 [ecryptfs]
Aug 27 10:46:45 office103-148 kernel: [<c050b96f>] destroy_inode+0x34/0x57
Aug 27 10:46:45 office103-148 kernel: [<c050c2fa>] generic_delete_inode+0x139/0x15e
Aug 27 10:46:45 office103-148 kernel: [<c050b458>] iput+0x5e/0x73
Aug 27 10:46:45 office103-148 kernel: [<c0508a95>] dentry_iput+0xad/0xd7
Aug 27 10:46:45 office103-148 kernel: [<c0508baa>] d_kill+0x2f/0x5b
Aug 27 10:46:45 office103-148 kernel: [<c050a4ab>] dput+0x103/0x120
Aug 27 10:46:45 office103-148 kernel: [<c0504483>] sys_renameat+0x189/0x1f3
Aug 27 10:46:45 office103-148 kernel: [<c050a401>] ? dput+0x59/0x120
Aug 27 10:46:45 office103-148 kernel: [<c0504512>] sys_rename+0x25/0x38
Aug 27 10:46:45 office103-148 kernel: [<c0403a50>] syscall_call+0x7/0xb
Aug 27 10:46:45 office103-148 kernel: iint_free: writecount: -1
Aug 27 10:46:45 office103-148 kernel: iint_free: opencount: -1


Version-Release number of selected component (if applicable):

kernel-2.6.31-0.180.rc7.git4.fc12.i686

How reproducible:


Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Eric Paris 2009-08-28 12:36:35 UTC

Thanks for the report, they should be harmless messages.  Is it causing you problems?  Its a report that ima didn't properly track how many reader and writers the file had.  So it is letting us know there is a bug, which I'll take a look at today, but it shouldn't cause you trouble (other than tons of logs)

Comment 2 Mark Wielaard 2009-09-18 14:04:17 UTC

Seeing similar messages with 2.6.31-23

Sep 18 15:50:28 rawhide kernel: ima_file_free: efd18a0bcae7697651f794fd2d2ebcf66faf62 open/free imbalance (r:0 w:0 o:0 f:0)
Sep 18 15:50:28 rawhide kernel: Pid: 1382, comm: git-describe Tainted: G        W  2.6.31-23.fc12.x86_64 #1
Sep 18 15:50:28 rawhide kernel: Call Trace:
Sep 18 15:50:28 rawhide kernel: [<ffffffff812487ae>] ima_file_free+0xc1/0x14b
Sep 18 15:50:28 rawhide kernel: [<ffffffff8122f801>] ? selinux_file_free_security+0x36/0x4c
Sep 18 15:50:28 rawhide kernel: [<ffffffff81144151>] __fput+0x147/0x200
Sep 18 15:50:28 rawhide kernel: [<ffffffff81144237>] fput+0x2d/0x43
Sep 18 15:50:28 rawhide kernel: [<ffffffff8114d026>] release_open_intent+0x36/0x4c
Sep 18 15:50:28 rawhide kernel: [<ffffffff8114f7a5>] do_filp_open+0x5c9/0x9f3
Sep 18 15:50:28 rawhide kernel: [<ffffffff8115b584>] ? alloc_fd+0x4a/0x14b
Sep 18 15:50:28 rawhide kernel: [<ffffffff8111383c>] ? might_fault+0x71/0xd9
Sep 18 15:50:28 rawhide kernel: [<ffffffff8115b65f>] ? alloc_fd+0x125/0x14b
Sep 18 15:50:28 rawhide kernel: [<ffffffff811405bd>] do_sys_open+0x71/0x131
Sep 18 15:50:28 rawhide kernel: [<ffffffff811406ea>] sys_open+0x33/0x49
Sep 18 15:50:28 rawhide kernel: [<ffffffff81011f42>] system_call_fastpath+0x16/0x1b
Sep 18 15:50:28 rawhide kernel: ima_file_free: efd18a0bcae7697651f794fd2d2ebcf66faf62 open/free imbalance (r:0 w:0 o:0 f:0)
Sep 18 15:51:37 rawhide kernel: ima_file_free: efd18a0bcae7697651f794fd2d2ebcf66faf62 open/free imbalance (r:0 w:0 o:0 f:0)

Comment 3 Eric Paris 2009-10-05 14:29:30 UTC

Comment #1 is being worked on upstream.  Discussion is here:
http://patchwork.kernel.org/patch/50600/

Comment #3 is a separate issue but it is also going to be looked at upstream.

Comment 4 Bug Zapper 2009-11-16 11:46:11 UTC

This bug appears to have been reported against 'rawhide' during the Fedora 12 development cycle.
Changing version to '12'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 5 Cristian Ciupitu 2009-12-04 21:36:38 UTC

I'm using kernel-2.6.31.6-145.fc12.x86_64, firefox-3.5.5-1.fc12.x86_64, xfsprogs-3.0.3-2.fc12.x86_64 and polkit-gnome-0.95-0.git20090913.6.fc12.x86_64 and I'm still encountering these messages:

ima_file_free:  open/free imbalance (r:0 w:0 o:0 f:0)
Pid: 3291, comm: xfs_fsr Tainted: P           2.6.31.6-145.fc12.x86_64 #1
Call Trace:
 [<ffffffff811d53e8>] ima_file_free+0xa7/0x10c
 [<ffffffff810fd946>] __fput+0x138/0x1da
 [<ffffffff810fda02>] fput+0x1a/0x1c
 [<ffffffff810faa7f>] filp_close+0x68/0x72
 [<ffffffff810fab26>] sys_close+0x9d/0xd2
 [<ffffffff81011cf2>] system_call_fastpath+0x16/0x1b

ima_file_free:  open/free imbalance (r:0 w:0 o:0 f:0)
Pid: 3291, comm: xfs_fsr Tainted: P           2.6.31.6-145.fc12.x86_64 #1
Call Trace:
 [<ffffffff811d53e8>] ima_file_free+0xa7/0x10c
 [<ffffffff810fd946>] __fput+0x138/0x1da
 [<ffffffff810fda02>] fput+0x1a/0x1c
 [<ffffffff810faa7f>] filp_close+0x68/0x72
 [<ffffffff810fab26>] sys_close+0x9d/0xd2
 [<ffffffff81011cf2>] system_call_fastpath+0x16/0x1b

ima_file_free: cookies.sqlite open/free imbalance (r:0 w:0 o:0 f:0)
Pid: 20907, comm: firefox Tainted: P           2.6.31.6-145.fc12.x86_64 #1
Call Trace:
 [<ffffffff811d53e8>] ima_file_free+0xa7/0x10c
 [<ffffffff810fd946>] __fput+0x138/0x1da
 [<ffffffff810fda02>] fput+0x1a/0x1c
 [<ffffffff810faa7f>] filp_close+0x68/0x72
 [<ffffffff81053459>] put_files_struct+0x6a/0xb9
 [<ffffffff810534e2>] exit_files+0x3a/0x3f
 [<ffffffff81054d93>] do_exit+0x210/0x6cb
 [<ffffffff8141d0d9>] ? do_page_fault+0x269/0x299
 [<ffffffff810552d1>] do_group_exit+0x83/0xb3
 [<ffffffff81055318>] sys_exit_group+0x17/0x1b
 [<ffffffff81011cf2>] system_call_fastpath+0x16/0x1b

ima_file_free: cookies.sqlite-journal open/free imbalance (r:0 w:0 o:0 f:0)
Pid: 20907, comm: firefox Tainted: P           2.6.31.6-145.fc12.x86_64 #1
Call Trace:
 [<ffffffff811d53e8>] ima_file_free+0xa7/0x10c
 [<ffffffff810fd946>] __fput+0x138/0x1da
 [<ffffffff810fda02>] fput+0x1a/0x1c
 [<ffffffff810faa7f>] filp_close+0x68/0x72
 [<ffffffff81053459>] put_files_struct+0x6a/0xb9
 [<ffffffff810534e2>] exit_files+0x3a/0x3f
 [<ffffffff81054d93>] do_exit+0x210/0x6cb
 [<ffffffff8141d0d9>] ? do_page_fault+0x269/0x299
 [<ffffffff810552d1>] do_group_exit+0x83/0xb3
 [<ffffffff81055318>] sys_exit_group+0x17/0x1b
 [<ffffffff81011cf2>] system_call_fastpath+0x16/0x1b

ima_file_free: .xsession-errors open/free imbalance (r:0 w:0 o:0 f:0)
Pid: 1848, comm: polkit-gnome-au Tainted: P           2.6.31.6-145.fc12.x86_64 #1
Call Trace:
 [<ffffffff811d53e8>] ima_file_free+0xa7/0x10c
 [<ffffffff810fd946>] __fput+0x138/0x1da
 [<ffffffff810fda02>] fput+0x1a/0x1c
 [<ffffffff810faa7f>] filp_close+0x68/0x72
 [<ffffffff81053459>] put_files_struct+0x6a/0xb9
 [<ffffffff810534e2>] exit_files+0x3a/0x3f
 [<ffffffff81054d93>] do_exit+0x210/0x6cb
 [<ffffffff8141d0d9>] ? do_page_fault+0x269/0x299
 [<ffffffff810552d1>] do_group_exit+0x83/0xb3
 [<ffffffff81055318>] sys_exit_group+0x17/0x1b
 [<ffffffff81011cf2>] system_call_fastpath+0x16/0x1b

Comment 6 Eric Paris 2010-02-05 21:30:48 UTC

these should be fixed in .33 upstream