Bug 15673

Summary: 2.6.34-rc2: "ima_dec_counts: open/free imbalance"?
Product: Drivers Reporter: Maciej Rutecki (maciej.rutecki)
Component: Video(DRI - Intel)Assignee: drivers_video-dri-intel (drivers_video-dri-intel)
Status: CLOSED CODE_FIX    
Severity: normal CC: chris, florian, maciej.rutecki, rjw, thomas, zohar
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.34-rc2 Subsystem:
Regression: Yes Bisected commit-id:
Bug Depends on:    
Bug Blocks: 7216, 15310    
Attachments: config for 2.6.34
dmesg with warning
the warning can also be seen in 2.6.35-rc6
config for 2.6.35-rc6

Description Maciej Rutecki 2010-04-01 19:07:38 UTC
Subject    : 2.6.34-rc2: "ima_dec_counts: open/free imbalance"?
Submitter  : Thomas Meyer <thomas@m3y3r.de>
Date       : 2010-03-28 11:31
Message-ID : 1269775909.5301.4.camel@localhost.localdomain
References : http://marc.info/?l=linux-kernel&m=126977593326800&w=2

This entry is being used for tracking a regression from 2.6.33.  Please don't
close it until the problem is fixed in the mainline.
Comment 1 Thomas Meyer 2010-06-21 15:05:15 UTC
Created attachment 26881 [details]
config for 2.6.34
Comment 2 Thomas Meyer 2010-06-21 15:05:58 UTC
I don't see the warning anymore with above config and plain 2.6.34.
Comment 3 Thomas Meyer 2010-06-26 12:38:36 UTC
Created attachment 26952 [details]
dmesg with warning

Stop! I still see this warning with 2.6.34. See attached dmesg. this warning is seen with also attached config.
Comment 4 Rafael J. Wysocki 2010-07-10 12:59:02 UTC
On Saturday, July 10, 2010, Thomas Meyer wrote:
> Am Samstag, den 10.07.2010, 02:33 +0200 schrieb Rafael J. Wysocki:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.33 and 2.6.34.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.33 and 2.6.34.  Please verify if it still should
> > be listed and let the tracking team know (either way).
> > 
> > 
> > Bug-Entry   : http://bugzilla.kernel.org/show_bug.cgi?id=15673
> > Subject             : 2.6.34-rc2: "ima_dec_counts: open/free imbalance"?
> > Submitter   : Thomas Meyer <thomas@m3y3r.de>
> > Date                : 2010-03-28 11:31 (104 days old)
> 
> Still see the warning in 2.6.34.1:
> 
> [ 1466.091349] IMA: unmeasured files on fsmagic: 1021994
> [ 1466.091356] ima_dec_counts: open/free imbalance (r:0 w:-1 o:-1)
> [ 1466.091360] Pid: 2357, comm: async/10 Tainted: G        W  2.6.34.1 #3
> [ 1466.091362] Call Trace:
> [ 1466.091371]  [<c08865c7>] ? printk+0x1d/0x26
> [ 1466.091377]  [<c05f994f>] ima_file_free+0x16f/0x210
> [ 1466.091384]  [<c04d7742>] __fput+0xf2/0x1f0
> [ 1466.091388]  [<c04d785d>] fput+0x1d/0x30
> [ 1466.091394]  [<c06cad8f>] drm_gem_object_free_common+0x1f/0x40
> [ 1466.091398]  [<c06cae30>] ? drm_gem_object_free+0x0/0x40
> [ 1466.091402]  [<c06cae61>] drm_gem_object_free+0x31/0x40
> [ 1466.091407]  [<c061d59c>] kref_put+0x2c/0x60
> [ 1466.091412]  [<c06e7308>] i915_gem_cleanup_ringbuffer+0x48/0x70
> [ 1466.091416]  [<c06e8a6c>] i915_gem_idle+0x9c/0x120
> [ 1466.091420]  [<c06dbe1d>] i915_drm_freeze+0x3d/0xa0
> [ 1466.091423]  [<c06dbfde>] i915_pm_suspend+0x2e/0x80
> [ 1466.091427]  [<c0886d0a>] ? wait_for_common+0x1a/0xf0
> [ 1466.091432]  [<c0636629>] pci_pm_suspend+0x49/0x110
> [ 1466.091436]  [<c06365e0>] ? pci_pm_suspend+0x0/0x110
> [ 1466.091441]  [<c0718be1>] pm_op+0x181/0x1d0
> [ 1466.091445]  [<c0711d34>] ? device_for_each_child+0x54/0x60
> [ 1466.091449]  [<c071959f>] __device_suspend+0xbf/0x110
> [ 1466.091453]  [<c07199e3>] async_suspend+0x23/0x60
> [ 1466.091457]  [<c0450025>] async_thread+0xc5/0x210
> [ 1466.091461]  [<c0886931>] ? schedule+0x1e1/0x450
> [ 1466.091472]  [<c042bd60>] ? default_wake_function+0x0/0x20
> [ 1466.091476]  [<c044ff60>] ? async_thread+0x0/0x210
> [ 1466.091480]  [<c04493c4>] kthread+0x74/0x80
> [ 1466.091483]  [<c0449350>] ? kthread+0x0/0x80
> [ 1466.091488]  [<c040347e>] kernel_thread_helper+0x6/0x10
> [ 1466.096531] iint_free: writecount: -1
> [ 1466.096533] iint_free: opencount: -1
> [ 1466.096535] iint_free: writecount: -1
> [ 1466.096537] iint_free: opencount: -1
> [ 1466.103256] ehci_hcd 0000:00:1d.7: PCI INT A disabled
Comment 5 Thomas Meyer 2010-07-24 11:25:04 UTC
Created attachment 27237 [details]
the warning can also be seen in 2.6.35-rc6
Comment 6 Thomas Meyer 2010-07-24 11:26:16 UTC
Created attachment 27238 [details]
config for 2.6.35-rc6
Comment 7 Thomas Meyer 2010-08-05 12:50:30 UTC
still in 2.6.35:

[ 3123.733374] IMA: unmeasured files on fsmagic: 1021994
[ 3123.733377] ima_dec_counts: open/free imbalance (r:0 w:-1 o:-1)
[ 3123.733382] Pid: 2886, comm: async/10 Tainted: G          I 2.6.35 #2
[ 3123.733384] Call Trace:
[ 3123.733394]  [<c05cd4e3>] ? ima_file_free+0x163/0x1c0
[ 3123.733405]  [<c04b5a99>] ? fput+0x119/0x220
[ 3123.733411]  [<c06956a7>] ? drm_gem_object_release+0x17/0x40
[ 3123.733416]  [<c06b2430>] ? i915_gem_free_object+0x50/0xc0
[ 3123.733420]  [<c0695660>] ? drm_gem_object_free+0x0/0x30
[ 3123.733424]  [<c069567d>] ? drm_gem_object_free+0x1d/0x30
[ 3123.733428]  [<c05edcd9>] ? kref_put+0x29/0x60
[ 3123.733433]  [<c06cb49b>] ? intel_cleanup_ring_buffer+0x3b/0x70
[ 3123.733437]  [<c06b0be1>] ? i915_gem_cleanup_ringbuffer+0x11/0x30
[ 3123.733440]  [<c06b2236>] ? i915_gem_idle+0x86/0xf0
[ 3123.733444]  [<c06a5ce8>] ? i915_drm_freeze+0x38/0xb0
[ 3123.733448]  [<c06a5ea8>] ? i915_pm_suspend+0x28/0x80
[ 3123.733452]  [<c0606305>] ? pci_pm_suspend+0x45/0x110
[ 3123.733456]  [<c06062c0>] ? pci_pm_suspend+0x0/0x110
[ 3123.733460]  [<c06df5b3>] ? pm_op+0x193/0x1e0
[ 3123.733464]  [<c06df240>] ? dpm_wait_fn+0x0/0x10
[ 3123.733469]  [<c06d8e13>] ? device_for_each_child+0x43/0x50
[ 3123.733473]  [<c06dffbf>] ? __device_suspend+0xbf/0x110
[ 3123.733477]  [<c06e03fd>] ? async_suspend+0x1d/0x50
[ 3123.733482]  [<c0444b25>] ? async_thread+0xc5/0x210
[ 3123.733486]  [<c0427b25>] ? finish_task_switch.clone.0+0x25/0x90
[ 3123.733490]  [<c0428c90>] ? default_wake_function+0x0/0x10
[ 3123.733494]  [<c0444a60>] ? async_thread+0x0/0x210
[ 3123.733498]  [<c043eb14>] ? kthread+0x74/0x80
[ 3123.733501]  [<c043eaa0>] ? kthread+0x0/0x80
[ 3123.733505]  [<c04032be>] ? kernel_thread_helper+0x6/0x18
[ 3123.739698] iint_free: writecount: -1
[ 3123.739700] iint_free: opencount: -1
[ 3123.739702] iint_free: writecount: -1
[ 3123.739704] iint_free: opencount: -1
Comment 8 Mimi Zohar 2010-08-31 19:10:27 UTC
The IMA counters are incremented/decremented only after IMA has been initialized.  It seems the 'imbalance' message occurs only when the i915 is builtin, not as a module. It seems when i915 is builtin, the ring_buffer
is initialized before IMA.  I've posted a patch which should resolve this bug on the LSM mailing list, copying stable.

Mimi
Comment 9 Florian Mickler 2010-12-22 08:09:23 UTC
Still there in 2.6.36 or current 2.6.37-rc7?
Comment 10 Thomas Meyer 2010-12-22 09:14:06 UTC
Fixed by commit e950598d43dce8d97e7d5270808393425d1e5cbd (ima: always maintain counters), that went in 2.6.36-rc4
Comment 11 Chris Wilson 2010-12-22 10:35:54 UTC
commit e950598d43dce8d97e7d5270808393425d1e5cbd
Author: Mimi Zohar <zohar@linux.vnet.ibm.com>
Date:   Tue Aug 31 09:38:51 2010 -0400

    ima: always maintain counters
    
    commit 8262bb85da allocated the inode integrity struct (iint) before any
    inodes were created. Only after IMA was initialized in late_initcall were
    the counters updated. This patch updates the counters, whether or not IMA
    has been initialized, to resolve 'imbalance' messages.
    
    This patch fixes the bug as reported in bugzilla: 15673.  When the i915
    is builtin, the ring_buffer is initialized before IMA, causing the
    imbalance message on suspend.
    
    Reported-by: Thomas Meyer <thomas@m3y3r.de>
    Signed-off-by: Mimi Zohar <zohar@linux.vnet.ibm.com>
    Tested-by: Thomas Meyer <thomas@m3y3r.de>
    Tested-by: David Safford<safford@watson.ibm.com>
    Cc: Stable Kernel <stable@kernel.org>
    Signed-off-by: James Morris <jmorris@namei.org>