Bug 1062439 - [ INFO: possible irq lock inversion dependency detected ] - BTRFS
Summary: [ INFO: possible irq lock inversion dependency detected ] - BTRFS
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: rawhide
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: fedora-kernel-btrfs
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-02-06 23:26 UTC by poma
Modified: 2014-04-15 22:41 UTC (History)
8 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2014-02-19 15:37:38 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Full dmesg (48.58 KB, text/plain)
2014-02-07 07:00 UTC, poma
no flags Details
dmesg - liveinst (65.34 KB, text/plain)
2014-02-08 01:06 UTC, poma
no flags Details
dmesg - post boot (43.30 KB, text/plain)
2014-02-08 01:10 UTC, poma
no flags Details
dmesg - liveinst - 3.14.0-0.rc1.git3.1 (63.57 KB, text/plain)
2014-02-09 18:04 UTC, poma
no flags Details
dmesg - 3.14.0-0.rc1.git4.1 - liveinst - btrfs - irq-lock - dma-debug - ahci-sata (62.43 KB, text/plain)
2014-02-10 04:49 UTC, poma
no flags Details
dmesg 3.14.0-0.rc1.git5.1 btrfs & scsi (59.97 KB, text/plain)
2014-02-11 03:13 UTC, poma
no flags Details
dmesg 3.14.0-0.rc2.git0.1 (70.15 KB, text/plain)
2014-02-12 05:13 UTC, poma
no flags Details
Test completato con successo (83.57 KB, text/plain)
2014-02-19 15:36 UTC, poma
no flags Details

Description poma 2014-02-06 23:26:16 UTC
http://koji.fedoraproject.org/koji/taskinfo?taskID=6500379
http://kojipkgs.fedoraproject.org//work/tasks/379/6500379/Fedora-Live-Xfce-x86_64-rawhide-20140206.iso

sha256sum:
13b0844cc646254f3fc0ea60dba402738d32535566c4c4e94f5209c532d1a26c  Fedora-Live-Xfce-x86_64-rawhide-20140206.iso

checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140206.iso:   b7b4a0107fad9f08854134d4a2762568
Fragment sums: 34d8b16565a3d5e5a865ebdf81d4552a4a91fd38f9a38b6b7e9139278e3b
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.

[liveuser@localhost ~]$ anaconda --version
Starting installer, one moment...
dm.c: 1693: not running as root returning empty list
anaconda 21.20-1

[liveuser@localhost ~]$ cat /usr/lib/python2.7/site-packages/blivet-0.40-py2.7.egg-info
Metadata-Version: 1.0
Name: blivet
Version: 0.40
Summary: Python module for system storage configuration
Home-page: http://fedoraproject.org/wiki/blivet
Author: David Lehman
Author-email: dlehman
License: UNKNOWN
Description: UNKNOWN
Platform: UNKNOWN

[liveuser@localhost ~]$ hostnamectl 
   Static hostname: localhost
         Icon name: computer-vm
           Chassis: vm
        Machine ID: 1918dced9afb7f657c1169df165932b3
           Boot ID: 3e87947f606d43e2a13d64afd9819957
  Operating System: Fedora 21 (Rawhide)
       CPE OS Name: cpe:/o:fedoraproject:fedora:21
            Kernel: Linux 3.14.0-0.rc1.git1.1.fc21.x86_64
      Architecture: x86_64

~~~~~~~~~~~~~~~~~~~~~~~~~~
MANUAL PARTITIONING
Create them automatically:
BTRFS - Create - Done
~~~~~~~~~~~~~~~~~~~~~~~~~~

dmesg:
…
BTRFS: device label fedora devid 1 transid 14 /dev/vda3
BTRFS: device label fedora devid 1 transid 14 /dev/vda3
BTRFS: device label fedora devid 1 transid 14 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
BTRFS: device label fedora devid 1 transid 15 /dev/vda3
BTRFS: device label fedora devid 1 transid 15 /dev/vda3
BTRFS: device label fedora devid 1 transid 15 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
EXT4-fs (vda1): INFO: recovery required on readonly filesystem
EXT4-fs (vda1): write access will be enabled during recovery
EXT4-fs (vda1): recovery complete
EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
SELinux: initialized (dev vda1, type ext4), uses xattr
BTRFS: device label fedora devid 1 transid 16 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
BTRFS: device label fedora devid 1 transid 16 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
SELinux: initialized (dev dm-1, type ext4), uses xattr
SGI XFS with ACLs, security attributes, large block/inode numbers, no debug enabled
BTRFS: device label fedora devid 1 transid 16 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
BTRFS: device label fedora devid 1 transid 18 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
BTRFS: device label fedora devid 1 transid 4 /dev/vda3
BTRFS: device label fedora devid 1 transid 4 /dev/vda3
BTRFS: device label fedora devid 1 transid 4 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
BTRFS: flagging fs with big metadata feature
BTRFS: creating UUID tree
SELinux: initialized (dev vda3, type btrfs), uses xattr
BTRFS: device label fedora devid 1 transid 7 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
Adding 838652k swap on /dev/vda2.  Priority:-1 extents:1 across:838652k FS
BTRFS: device label fedora devid 1 transid 9 /dev/vda3
BTRFS info (device vda3): disk space caching is enabled
SELinux: initialized (dev vda3, type btrfs), uses xattr
EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
SELinux: initialized (dev vda1, type ext4), uses xattr
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
BTRFS: device label fedora devid 1 transid 9 /dev/vda3

=========================================================
[ INFO: possible irq lock inversion dependency detected ]
3.14.0-0.rc1.git1.1.fc21.x86_64 #1 Not tainted
---------------------------------------------------------
kswapd0/30 just changed the state of lock:
 (&delayed_node->mutex){+.+.-.}, at: [<ffffffffa01e09ad>] __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
but this lock took another, RECLAIM_FS-unsafe lock in the past:
 (&found->groups_sem){+++++.}

and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
 Possible interrupt unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&found->groups_sem);
                               local_irq_disable();
                               lock(&delayed_node->mutex);
                               lock(&found->groups_sem);
  <Interrupt>
    lock(&delayed_node->mutex);

 *** DEADLOCK ***

2 locks held by kswapd0/30:
 #0:  (shrinker_rwsem){++++..}, at: [<ffffffff811c45af>] shrink_slab+0x3f/0x180
 #1:  (&type->s_umount_key#49){+++++.}, at: [<ffffffff81236a74>] grab_super_passive+0x44/0x90

the shortest dependencies between 2nd lock and 1st lock:
 -> (&found->groups_sem){+++++.} ops: 4248 {
    HARDIRQ-ON-W at:
                      [<ffffffff810f9479>] __lock_acquire+0x659/0x1c40
                      [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                      [<ffffffff817d6e6e>] down_write+0x4e/0xc0
                      [<ffffffffa017785b>] __link_block_group+0x3b/0xf0 [btrfs]
                      [<ffffffffa017973b>] btrfs_read_block_groups+0x30b/0x690 [btrfs]
                      [<ffffffffa0188a79>] open_ctree+0x17f9/0x21e0 [btrfs]
                      [<ffffffffa015bc5e>] btrfs_mount+0x63e/0x810 [btrfs]
                      [<ffffffff81237449>] mount_fs+0x39/0x1b0
                      [<ffffffff8125780b>] vfs_kern_mount+0x6b/0x150
                      [<ffffffff8125a6de>] do_mount+0x24e/0xbb0
                      [<ffffffff8125b386>] SyS_mount+0x96/0xf0
                      [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
    HARDIRQ-ON-R at:
                      [<ffffffff810f9360>] __lock_acquire+0x540/0x1c40
                      [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                      [<ffffffff817d6dd1>] down_read+0x51/0xa0
                      [<ffffffffa0183fed>] btrfs_calc_num_tolerated_disk_barrier_failures+0x1cd/0x350 [btrfs]
                      [<ffffffffa0188a97>] open_ctree+0x1817/0x21e0 [btrfs]
                      [<ffffffffa015bc5e>] btrfs_mount+0x63e/0x810 [btrfs]
                      [<ffffffff81237449>] mount_fs+0x39/0x1b0
                      [<ffffffff8125780b>] vfs_kern_mount+0x6b/0x150
                      [<ffffffff8125a6de>] do_mount+0x24e/0xbb0
                      [<ffffffff8125b386>] SyS_mount+0x96/0xf0
                      [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
    SOFTIRQ-ON-W at:
                      [<ffffffff810f94af>] __lock_acquire+0x68f/0x1c40
                      [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                      [<ffffffff817d6e6e>] down_write+0x4e/0xc0
                      [<ffffffffa017785b>] __link_block_group+0x3b/0xf0 [btrfs]
                      [<ffffffffa017973b>] btrfs_read_block_groups+0x30b/0x690 [btrfs]
                      [<ffffffffa0188a79>] open_ctree+0x17f9/0x21e0 [btrfs]
                      [<ffffffffa015bc5e>] btrfs_mount+0x63e/0x810 [btrfs]
                      [<ffffffff81237449>] mount_fs+0x39/0x1b0
                      [<ffffffff8125780b>] vfs_kern_mount+0x6b/0x150
                      [<ffffffff8125a6de>] do_mount+0x24e/0xbb0
                      [<ffffffff8125b386>] SyS_mount+0x96/0xf0
                      [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
    SOFTIRQ-ON-R at:
                      [<ffffffff810f94af>] __lock_acquire+0x68f/0x1c40
                      [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                      [<ffffffff817d6dd1>] down_read+0x51/0xa0
                      [<ffffffffa0183fed>] btrfs_calc_num_tolerated_disk_barrier_failures+0x1cd/0x350 [btrfs]
                      [<ffffffffa0188a97>] open_ctree+0x1817/0x21e0 [btrfs]
                      [<ffffffffa015bc5e>] btrfs_mount+0x63e/0x810 [btrfs]
                      [<ffffffff81237449>] mount_fs+0x39/0x1b0
                      [<ffffffff8125780b>] vfs_kern_mount+0x6b/0x150
                      [<ffffffff8125a6de>] do_mount+0x24e/0xbb0
                      [<ffffffff8125b386>] SyS_mount+0x96/0xf0
                      [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
    RECLAIM_FS-ON-W at:
                         [<ffffffff810f8819>] mark_held_locks+0xb9/0x140
                         [<ffffffff810fbc4a>] lockdep_trace_alloc+0x7a/0xe0
                         [<ffffffff8121180f>] __kmalloc_track_caller+0x4f/0x350
                         [<ffffffff813d6e21>] kvasprintf+0x61/0xa0
                         [<ffffffff813c9601>] kobject_set_name_vargs+0x21/0x70
                         [<ffffffff813ca092>] kobject_add+0x62/0xd0
                         [<ffffffffa01778e4>] __link_block_group+0xc4/0xf0 [btrfs]
                         [<ffffffffa017973b>] btrfs_read_block_groups+0x30b/0x690 [btrfs]
                         [<ffffffffa0188a79>] open_ctree+0x17f9/0x21e0 [btrfs]
                         [<ffffffffa015bc5e>] btrfs_mount+0x63e/0x810 [btrfs]
                         [<ffffffff81237449>] mount_fs+0x39/0x1b0
                         [<ffffffff8125780b>] vfs_kern_mount+0x6b/0x150
                         [<ffffffff8125a6de>] do_mount+0x24e/0xbb0
                         [<ffffffff8125b386>] SyS_mount+0x96/0xf0
                         [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
    INITIAL USE at:
                     [<ffffffff810f9167>] __lock_acquire+0x347/0x1c40
                     [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                     [<ffffffff817d6e6e>] down_write+0x4e/0xc0
                     [<ffffffffa017785b>] __link_block_group+0x3b/0xf0 [btrfs]
                     [<ffffffffa017973b>] btrfs_read_block_groups+0x30b/0x690 [btrfs]
                     [<ffffffffa0188a79>] open_ctree+0x17f9/0x21e0 [btrfs]
                     [<ffffffffa015bc5e>] btrfs_mount+0x63e/0x810 [btrfs]
                     [<ffffffff81237449>] mount_fs+0x39/0x1b0
                     [<ffffffff8125780b>] vfs_kern_mount+0x6b/0x150
                     [<ffffffff8125a6de>] do_mount+0x24e/0xbb0
                     [<ffffffff8125b386>] SyS_mount+0x96/0xf0
                     [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
  }
  ... key      at: [<ffffffffa021c7e0>] __key.42525+0x0/0xfffffffffffe5820 [btrfs]
  ... acquired at:
   [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
   [<ffffffff817d6dd1>] down_read+0x51/0xa0
   [<ffffffffa017719b>] find_free_extent+0x80b/0xe90 [btrfs]
   [<ffffffffa01779d8>] btrfs_reserve_extent+0xa8/0x140 [btrfs]
   [<ffffffffa0177cee>] btrfs_alloc_free_block+0xfe/0x480 [btrfs]
   [<ffffffffa01611f4>] __btrfs_cow_block+0x134/0x550 [btrfs]
   [<ffffffffa01617a6>] btrfs_cow_block+0x116/0x270 [btrfs]
   [<ffffffffa0165630>] btrfs_search_slot+0x1e0/0xa30 [btrfs]
   [<ffffffffa01e14ac>] btrfs_delete_delayed_items+0xcc/0x330 [btrfs]
   [<ffffffffa01e1ed2>] __btrfs_run_delayed_items+0x122/0x1e0 [btrfs]
   [<ffffffffa01e1fc3>] btrfs_run_delayed_items+0x13/0x20 [btrfs]
   [<ffffffffa018a449>] btrfs_flush_all_pending_stuffs+0x19/0x70 [btrfs]
   [<ffffffffa018b512>] btrfs_commit_transaction+0x232/0xaa0 [btrfs]
   [<ffffffffa0156354>] btrfs_sync_fs+0x54/0x160 [btrfs]
   [<ffffffff8126aff5>] sync_filesystem+0x85/0xc0
   [<ffffffff81235500>] generic_shutdown_super+0x30/0xf0
   [<ffffffff812357a2>] kill_anon_super+0x12/0x20
   [<ffffffffa0158a06>] btrfs_kill_super+0x16/0x90 [btrfs]
   [<ffffffff81235c7d>] deactivate_locked_super+0x3d/0x60
   [<ffffffff81236256>] deactivate_super+0x46/0x60
   [<ffffffff812582fd>] mntput_no_expire+0x17d/0x1f0
   [<ffffffff81259c5d>] SyS_umount+0x9d/0x110
   [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b

-> (&delayed_node->mutex){+.+.-.} ops: 250816 {
   HARDIRQ-ON-W at:
                    [<ffffffff810f9479>] __lock_acquire+0x659/0x1c40
                    [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                    [<ffffffff817d4687>] mutex_lock_nested+0x87/0x430
                    [<ffffffffa01e2663>] btrfs_delete_delayed_dir_index+0x83/0x200 [btrfs]
                    [<ffffffffa019523f>] btrfs_unlink_subvol+0x17f/0x360 [btrfs]
                    [<ffffffffa01be55a>] btrfs_ioctl_snap_destroy+0x47a/0x770 [btrfs]
                    [<ffffffffa01c42eb>] btrfs_ioctl+0x1c3b/0x2e10 [btrfs]
                    [<ffffffff81248750>] do_vfs_ioctl+0x300/0x520
                    [<ffffffff81248a11>] SyS_ioctl+0xa1/0xc0
                    [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
   SOFTIRQ-ON-W at:
                    [<ffffffff810f94af>] __lock_acquire+0x68f/0x1c40
                    [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                    [<ffffffff817d4687>] mutex_lock_nested+0x87/0x430
                    [<ffffffffa01e2663>] btrfs_delete_delayed_dir_index+0x83/0x200 [btrfs]
                    [<ffffffffa019523f>] btrfs_unlink_subvol+0x17f/0x360 [btrfs]
                    [<ffffffffa01be55a>] btrfs_ioctl_snap_destroy+0x47a/0x770 [btrfs]
                    [<ffffffffa01c42eb>] btrfs_ioctl+0x1c3b/0x2e10 [btrfs]
                    [<ffffffff81248750>] do_vfs_ioctl+0x300/0x520
                    [<ffffffff81248a11>] SyS_ioctl+0xa1/0xc0
                    [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
   IN-RECLAIM_FS-W at:
                       [<ffffffff810f93d4>] __lock_acquire+0x5b4/0x1c40
                       [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                       [<ffffffff817d4687>] mutex_lock_nested+0x87/0x430
                       [<ffffffffa01e09ad>] __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
                       [<ffffffffa01e22a4>] btrfs_remove_delayed_node+0x24/0x30 [btrfs]
                       [<ffffffffa0196eee>] btrfs_evict_inode+0x1ae/0x5d0 [btrfs]
                       [<ffffffff81252473>] evict+0xa3/0x1a0
                       [<ffffffff812525ae>] dispose_list+0x3e/0x50
                       [<ffffffff812535c6>] prune_icache_sb+0x56/0x80
                       [<ffffffff81236cd8>] super_cache_scan+0x108/0x180
                       [<ffffffff811c424b>] shrink_slab_node+0x14b/0x440
                       [<ffffffff811c45fe>] shrink_slab+0x8e/0x180
                       [<ffffffff811c744d>] kswapd_shrink_zone+0x14d/0x1f0
                       [<ffffffff811c9030>] kswapd+0x4b0/0xa60
                       [<ffffffff810c43cf>] kthread+0xff/0x120
                       [<ffffffff817e2cfc>] ret_from_fork+0x7c/0xb0
   INITIAL USE at:
                   [<ffffffff810f9167>] __lock_acquire+0x347/0x1c40
                   [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
                   [<ffffffff817d4687>] mutex_lock_nested+0x87/0x430
                   [<ffffffffa01e2663>] btrfs_delete_delayed_dir_index+0x83/0x200 [btrfs]
                   [<ffffffffa019523f>] btrfs_unlink_subvol+0x17f/0x360 [btrfs]
                   [<ffffffffa01be55a>] btrfs_ioctl_snap_destroy+0x47a/0x770 [btrfs]
                   [<ffffffffa01c42eb>] btrfs_ioctl+0x1c3b/0x2e10 [btrfs]
                   [<ffffffff81248750>] do_vfs_ioctl+0x300/0x520
                   [<ffffffff81248a11>] SyS_ioctl+0xa1/0xc0
                   [<ffffffff817e2da9>] system_call_fastpath+0x16/0x1b
 }
 ... key      at: [<ffffffffa0220738>] __key.37530+0x0/0xfffffffffffe18c8 [btrfs]
 ... acquired at:
   [<ffffffff810f7dea>] check_usage_forwards+0x16a/0x180
   [<ffffffff810f8657>] mark_lock+0x1a7/0x2b0
   [<ffffffff810f93d4>] __lock_acquire+0x5b4/0x1c40
   [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
   [<ffffffff817d4687>] mutex_lock_nested+0x87/0x430
   [<ffffffffa01e09ad>] __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
   [<ffffffffa01e22a4>] btrfs_remove_delayed_node+0x24/0x30 [btrfs]
   [<ffffffffa0196eee>] btrfs_evict_inode+0x1ae/0x5d0 [btrfs]
   [<ffffffff81252473>] evict+0xa3/0x1a0
   [<ffffffff812525ae>] dispose_list+0x3e/0x50
   [<ffffffff812535c6>] prune_icache_sb+0x56/0x80
   [<ffffffff81236cd8>] super_cache_scan+0x108/0x180
   [<ffffffff811c424b>] shrink_slab_node+0x14b/0x440
   [<ffffffff811c45fe>] shrink_slab+0x8e/0x180
   [<ffffffff811c744d>] kswapd_shrink_zone+0x14d/0x1f0
   [<ffffffff811c9030>] kswapd+0x4b0/0xa60
   [<ffffffff810c43cf>] kthread+0xff/0x120
   [<ffffffff817e2cfc>] ret_from_fork+0x7c/0xb0


stack backtrace:
CPU: 0 PID: 30 Comm: kswapd0 Not tainted 3.14.0-0.rc1.git1.1.fc21.x86_64 #1
Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
 0000000000000000 000000008ae747be ffff88007f3f9718 ffffffff817cef2d
 ffffffff82a1fec0 ffff88007f3f9758 ffffffff817ca5c6 ffffffff81a4d7ec
 0000000000000000 ffff880079ead7f0 ffff880079eacc50 ffffffff81a4d7ec
Call Trace:
 [<ffffffff817cef2d>] dump_stack+0x4d/0x66
 [<ffffffff817ca5c6>] print_irq_inversion_bug.part.42+0x1ac/0x1b8
 [<ffffffff810f7dea>] check_usage_forwards+0x16a/0x180
 [<ffffffff810f7c80>] ? check_usage_backwards+0x180/0x180
 [<ffffffff810f8657>] mark_lock+0x1a7/0x2b0
 [<ffffffff810f93d4>] __lock_acquire+0x5b4/0x1c40
 [<ffffffff810f8819>] ? mark_held_locks+0xb9/0x140
 [<ffffffff817d818c>] ? _raw_spin_unlock_irq+0x2c/0x40
 [<ffffffff810f8a7d>] ? trace_hardirqs_on+0xd/0x10
 [<ffffffff817d818c>] ? _raw_spin_unlock_irq+0x2c/0x40
 [<ffffffff810ceeed>] ? finish_task_switch+0x7d/0x130
 [<ffffffff810ceeaf>] ? finish_task_switch+0x3f/0x130
 [<ffffffff810fb252>] lock_acquire+0xa2/0x1d0
 [<ffffffffa01e09ad>] ? __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
 [<ffffffff817d4687>] mutex_lock_nested+0x87/0x430
 [<ffffffffa01e09ad>] ? __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
 [<ffffffff810dd26d>] ? sched_clock_local+0x1d/0x80
 [<ffffffffa01e09ad>] ? __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
 [<ffffffffa0196ec5>] ? btrfs_evict_inode+0x185/0x5d0 [btrfs]
 [<ffffffff810dd4b8>] ? sched_clock_cpu+0xa8/0xd0
 [<ffffffff810dd536>] ? local_clock+0x16/0x30
 [<ffffffffa01e09ad>] __btrfs_release_delayed_node+0x3d/0x1f0 [btrfs]
 [<ffffffffa01e22a4>] btrfs_remove_delayed_node+0x24/0x30 [btrfs]
 [<ffffffffa0196eee>] btrfs_evict_inode+0x1ae/0x5d0 [btrfs]
 [<ffffffff81252473>] evict+0xa3/0x1a0
 [<ffffffff812525ae>] dispose_list+0x3e/0x50
 [<ffffffff812535c6>] prune_icache_sb+0x56/0x80
 [<ffffffff81236cd8>] super_cache_scan+0x108/0x180
 [<ffffffff811c424b>] shrink_slab_node+0x14b/0x440
 [<ffffffff811c45af>] ? shrink_slab+0x3f/0x180
 [<ffffffff811c45fe>] shrink_slab+0x8e/0x180
 [<ffffffff811c744d>] kswapd_shrink_zone+0x14d/0x1f0
 [<ffffffff811c9030>] kswapd+0x4b0/0xa60
 [<ffffffff811c8b80>] ? mem_cgroup_shrink_node_zone+0x2f0/0x2f0
 [<ffffffff810c43cf>] kthread+0xff/0x120
 [<ffffffff810c42d0>] ? insert_kthread_work+0x80/0x80
 [<ffffffff817e2cfc>] ret_from_fork+0x7c/0xb0
 [<ffffffff810c42d0>] ? insert_kthread_work+0x80/0x80
JFS: nTxBlock = 8192, nTxLock = 65536
fuse init (API version 7.22)
SELinux: initialized (dev fusectl, type fusectl), uses genfs_contexts
BTRFS: device label fedora devid 1 transid 17 /dev/vda3

Comment 1 Chris Murphy 2014-02-07 01:01:08 UTC
I've notified upstream, will update once there's a URL to the thread.

Comment 3 poma 2014-02-07 07:00:06 UTC
Created attachment 860383 [details]
Full dmesg

Comment 4 Josh Boyer 2014-02-07 14:35:35 UTC
(In reply to Chris Murphy from comment #2)
> http://www.spinics.net/lists/linux-btrfs/msg31426.html

Thanks Chris.  We'll keep an eye on that thread.

Comment 5 poma 2014-02-08 01:00:58 UTC
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
WARNING: CPU: 1 PID: 2833 at lib/dma-debug.c:491 add_dma_entry+0x127/0x130()
DMA-API: exceeded 7 overlapping mappings of pfn 2137
~~~~~~~~~~                                                        ~~~~~~~~~~
[ INFO: possible irq lock inversion dependency detected ]
3.14.0-0.rc1.git2.1.fc21.x86_64 #1 Tainted: G        W
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

http://koji.fedoraproject.org/koji/taskinfo?taskID=6504886
http://kojipkgs.fedoraproject.org/work/tasks/4886/6504886/Fedora-Live-Xfce-x86_64-rawhide-20140207.iso


sha256sum:
2b755123cac9d1b3d8fbc58787ce15ce9de696831775b83157771db741f85ba8  Fedora-Live-Xfce-x86_64-rawhide-20140207.iso


checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140207.iso:   a4f2d1694ba9c81de820055c69ce154b
Fragment sums: 69c5e9bf5e9a33c154815de65ca9844368bd7bf1d724ea51af197c56ea6c
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.


/boot/extlinux/extlinux.conf:
ui menu.c32
menu title Fedora Rawhide EXTLINUX Boot
timeout 50

label Fedora Rawhide 3.14.0-0.rc1.git2.1.fc21.x86_64
	kernel /vmlinuz-3.14.0-0.rc1.git2.1.fc21.x86_64
	append root=UUID=bccb1505-e360-4c83-911d-b76f2eb7ae27 rootflags=subvol=root ro
	initrd /initramfs-3.14.0-0.rc1.git2.1.fc21.x86_64.img


/etc/fstab:
UUID=bccb1505-e360-4c83-911d-b76f2eb7ae27 /                       btrfs   subvol=root     0 0
UUID=4703308e-2c7d-406f-88da-928a93bae3e0 /boot                   ext4    defaults        1 2
UUID=bccb1505-e360-4c83-911d-b76f2eb7ae27 /home                   btrfs   subvol=home     0 0
UUID=6c928f25-ce5b-4690-9d83-70512f002adb swap                    swap    defaults        0 0


$ hostnamectl 
   Static hostname: localhost.localdomain
         Icon name: computer
           Chassis: n/a
        Machine ID: 95ff9ae320954d0384fa9aea75a9c1cd
           Boot ID: 2f7970466c36457183fd4095d4850bde
  Operating System: Fedora 21 (Rawhide)
       CPE OS Name: cpe:/o:fedoraproject:fedora:21
            Kernel: Linux 3.14.0-0.rc1.git2.1.fc21.x86_64
      Architecture: x86_64


# fdisk -l

Disk /dev/sda: 8 GiB, 8589934592 bytes, 16777216 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x0009c503

Device    Boot     Start       End  Blocks  Id System
/dev/sda1 *         2048   1026047  512000  83 Linux
/dev/sda2        1026048   2703359  838656  82 Linux swap / Solaris
/dev/sda3        2703360  16777215 7036928  83 Linux


# btrfs filesystem show /
Label: fedora  uuid: bccb1505-e360-4c83-911d-b76f2eb7ae27
	Total devices 1 FS bytes used 2.04GiB
	devid    1 size 6.71GiB used 2.72GiB path /dev/sda3

Btrfs v3.12


# btrfs filesystem df /
Data, single: total=2.02GiB, used=1.93GiB
System, DUP: total=8.00MiB, used=16.00KiB
System, single: total=4.00MiB, used=0.00
Metadata, DUP: total=343.56MiB, used=113.28MiB
Metadata, single: total=8.00MiB, used=0.00


# btrfs subvolume list -p -t /
ID	gen	parent	top level	path	
--	---	------	---------	----	
257	45	5	5		root
258	35	5	5		home


# btrfs subvolume show /
/
	Name: 			root
	uuid: 			c31ad3ed-d34e-694a-b18b-9b66fc53bae6
	Parent uuid: 		-
	Creation time: 		2014-02-07 18:56:18
	Object ID: 		257
	Generation (Gen): 	45
	Gen at creation: 	6
	Parent: 		5
	Top Level: 		5
	Flags: 			-
	Snapshot(s):
# btrfs subvolume show /home
/home
	Name: 			home
	uuid: 			e93050f3-7bd3-494a-b30b-c83edc764540
	Parent uuid: 		-
	Creation time: 		2014-02-07 18:56:19
	Object ID: 		258
	Generation (Gen): 	35
	Gen at creation: 	8
	Parent: 		5
	Top Level: 		5
	Flags: 			-
	Snapshot(s):

Comment 6 poma 2014-02-08 01:06:34 UTC
Created attachment 860783 [details]
dmesg - liveinst

Comment 7 poma 2014-02-08 01:10:49 UTC
Created attachment 860784 [details]
dmesg - post boot

Comment 8 Chris Murphy 2014-02-08 01:43:15 UTC
Huh, this is a newly created Btrfs file system, I presume created with live-xfce. When you boot from the Btrfs install, you get a dmesg devoid of problems. When you boot from live-xfce, you get the info lock warning. Am I interpreting this correctly?

I wonder if this is a problem with the initramfs, which would implicate dracut? I can't reproduce this lock message with three different Btrfs file systems of various ages, and the same kernel listed.

Comment 9 poma 2014-02-09 17:57:52 UTC
(In reply to Chris Murphy from comment #8)
> Huh, this is a newly created Btrfs file system, I presume created with
> live-xfce. When you boot from the Btrfs install, you get a dmesg devoid of
> problems. When you boot from live-xfce, you get the info lock warning. Am I
> interpreting this correctly?

Very well interpreted.

Comment 10 poma 2014-02-09 18:04:17 UTC
Created attachment 861122 [details]
dmesg - liveinst - 3.14.0-0.rc1.git3.1

Comment 11 poma 2014-02-09 18:06:30 UTC
http://koji.fedoraproject.org/koji/taskinfo?taskID=6507680
http://kojipkgs.fedoraproject.org//work/tasks/7680/6507680/Fedora-Live-Xfce-x86_64-rawhide-20140208.iso

sha256sum:
6f981b64e4fa6a64a31c08c0e21881744878d325094d403fdcff2cf8884c3a54  Fedora-Live-Xfce-x86_64-rawhide-20140208.iso
checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140208.iso:   b3fc7104c7644ba5c101d4714fa0377a
Fragment sums: 8f1a64f2042d464ab2187cee36921139244e3122f30c2a73ae7938c5feab
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.

anaconda-21.20-1.fc21.x86_64
python-blivet-0.40-1.fc21.noarch

Comment 12 poma 2014-02-10 04:49:09 UTC
Created attachment 861227 [details]
dmesg - 3.14.0-0.rc1.git4.1 - liveinst - btrfs - irq-lock - dma-debug - ahci-sata

Comment 13 poma 2014-02-10 04:50:40 UTC
http://koji.fedoraproject.org/koji/taskinfo?taskID=6509103
http://kojipkgs.fedoraproject.org//work/tasks/9103/6509103/Fedora-Live-Xfce-x86_64-rawhide-20140209.iso

sha256sum:
ec6625cb4f297cc4d38138c883486762144b8024de389cbde1ae6ad697f0d050  Fedora-Live-Xfce-x86_64-rawhide-20140209.iso

checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140209.iso:   3af8fbc1cfea0e37ec2fa9378b98b024
Fragment sums: 833a2f58bdf686ca739fec58195fe7aad09a6819936f2ed426565df8f9ce
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.

anaconda-21.20-1.fc21.x86_64
python-blivet-0.40-1.fc21.noarch

$ getenforce 
Disabled

$ liveinst --debug --noselinux --extlinux

Comment 14 poma 2014-02-11 03:10:48 UTC
http://koji.fedoraproject.org/koji/taskinfo?taskID=6513543
http://kojipkgs.fedoraproject.org//work/tasks/3543/6513543/Fedora-Live-Xfce-x86_64-rawhide-20140210.iso

sha256sum:
aa5c127d92edee36a71d7f8777d55402b025a44b766c5fd60c21bee10b1d7cdc  Fedora-Live-Xfce-x86_64-rawhide-20140210.iso

checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140210.iso:   114e04c9d16ef5f51e6642e66d499480
Fragment sums: 919524ba4ba3e2f98627ee4dd9eb6b44f165b53fe12d7d26ea769624fc31
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.

$ rpm -q anaconda python-blivet
anaconda-21.20-1.fc21.x86_64
python-blivet-0.40-1.fc21.noarch

$ getenforce 
Disabled

$ liveinst --debug --noselinux --extlinux

Comment 15 poma 2014-02-11 03:13:29 UTC
Created attachment 861651 [details]
dmesg 3.14.0-0.rc1.git5.1 btrfs & scsi

WARNING: at lib/dma-debug.c:491 add_dma_entry
DMA-API: exceeded 7 overlapping mappings of pfn

WARNING: at lib/dma-debug.c:1041 check_unmap
DMA-API: device driver tries to free DMA memory it has not allocated

INFO: possible irq lock inversion dependency detected

Comment 16 poma 2014-02-12 05:13:04 UTC
Created attachment 862118 [details]
dmesg 3.14.0-0.rc2.git0.1

Comment 17 poma 2014-02-12 05:17:00 UTC
http://koji.fedoraproject.org/koji/taskinfo?taskID=6516853
http://kojipkgs.fedoraproject.org//work/tasks/6853/6516853/Fedora-Live-Xfce-x86_64-rawhide-20140211.iso

sha256sum:
6d0f5ef215333bda425983ed332ec0b10d63c1f9c2058a4c1b5052eb704c9b02  Fedora-Live-Xfce-x86_64-rawhide-20140211.iso

checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140211.iso:   60682dd6186f7cccffe39b54e2ab9dc2
Fragment sums: cf5f68b9152afc6d3ba481fa1bb742ae898b91285e5e24f4867dcf7e9596
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.


$ lspci
00:00.0 Host bridge: Intel Corporation 440FX - 82441FX PMC [Natoma] (rev 02)
00:01.0 ISA bridge: Intel Corporation 82371SB PIIX3 ISA [Natoma/Triton II]
00:01.1 IDE interface: Intel Corporation 82371SB PIIX3 IDE [Natoma/Triton II]
00:01.3 Bridge: Intel Corporation 82371AB/EB/MB PIIX4 ACPI (rev 03)
00:02.0 VGA compatible controller: Red Hat, Inc. Device 0100 (rev 04)
00:03.0 Ethernet controller: Red Hat, Inc Virtio network device
00:04.0 Audio device: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) High Definition Audio Controller (rev 01)
00:05.0 USB controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #1 (rev 03)
00:05.1 USB controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #2 (rev 03)
00:05.2 USB controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #3 (rev 03)
00:05.7 USB controller: Intel Corporation 82801I (ICH9 Family) USB2 EHCI Controller #1 (rev 03)
00:06.0 Communication controller: Red Hat, Inc Virtio console
00:07.0 SCSI storage controller: Red Hat, Inc Virtio block device
00:08.0 Unclassified device [00ff]: Red Hat, Inc Virtio memory balloon


/etc/extlinux.conf
ui menu.c32
menu title Fedora Rawhide Boot
timeout 50

label Fedora (3.14.0-0.rc2.git0.1.fc21.x86_64)
	kernel /vmlinuz-3.14.0-0.rc2.git0.1.fc21.x86_64
	append root=UUID=db0450b0-8e82-4c41-ac12-626e33de73bf rootflags=subvol=root selinux=0
	initrd /initramfs-3.14.0-0.rc2.git0.1.fc21.x86_64.img


/etc/fstab 
UUID=db0450b0-8e82-4c41-ac12-626e33de73bf /                       btrfs   subvol=root     0 0
UUID=b2b9e8c1-2cf8-40b0-a801-b1782bf9f5ba /boot                   ext4    defaults        1 2
UUID=18eba188-7581-4c28-b01b-981f55ff8d8e swap                    swap    defaults        0 0


# fdisk -l

Disk /dev/vda: 8 GiB, 8589934592 bytes, 16777216 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x000e54b8

Device    Boot     Start       End  Blocks  Id System
/dev/vda1 *         2048   1026047  512000  83 Linux
/dev/vda2        1026048   2703359  838656  82 Linux swap / Solaris
/dev/vda3        2703360  16777215 7036928  83 Linux


# btrfs filesystem show /
Label: fedora  uuid: db0450b0-8e82-4c41-ac12-626e33de73bf
	Total devices 1 FS bytes used 2.03GiB
	devid    1 size 6.71GiB used 2.72GiB path /dev/vda3

Btrfs v3.12


# btrfs filesystem df /
Data, single: total=2.02GiB, used=1.92GiB
System, DUP: total=8.00MiB, used=16.00KiB
System, single: total=4.00MiB, used=0.00
Metadata, DUP: total=343.56MiB, used=112.80MiB
Metadata, single: total=8.00MiB, used=0.00


# btrfs subvolume list -p -t /
ID	gen	parent	top level	path	
--	---	------	---------	----	
257	29	5	5		root


# btrfs subvolume show /
/
	Name: 			root
	uuid: 			7912bc0b-7f15-6c4e-abf7-a39f994c3815
	Parent uuid: 		-
	Creation time: 		2014-02-11 23:34:45
	Object ID: 		257
	Generation (Gen): 	29
	Gen at creation: 	6
	Parent: 		5
	Top Level: 		5
	Flags: 			-
	Snapshot(s):


Can't rain all the time

Comment 19 poma 2014-02-19 15:35:21 UTC
http://koji.fedoraproject.org/koji/taskinfo?taskID=6546058
http://kojipkgs.fedoraproject.org//work/tasks/6058/6546058/Fedora-Live-Xfce-x86_64-rawhide-20140218.iso

checkisomd5:
Fedora-Live-Xfce-x86_64-rawhide-20140218.iso:   a41e2ca593dabb85c11b93e00f0cea5c
Fragment sums: 7ae9aa61747c75b9a5bbfb483184a65ab52fcd7df77ca62b8bece2d99ff7
Fragment count: 20
Press [Esc] to abort check.
Checking: 100.0%

The media check is complete, the result is: PASS.

It is OK to use this media.

sha256sum:
a03cd2b95496c72f726a4caf88cbc2a5fd2113bc6dbd8cfd99819ae8bc01b7c5  Fedora-Live-Xfce-x86_64-rawhide-20140218.iso


Test PASSED.
Thanks for your patience and see you some other time. ;)

Comment 20 poma 2014-02-19 15:36:17 UTC
Created attachment 865118 [details]
Test completato con successo


Note You need to log in before you can comment on or make changes to this bug.