Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S932071AbWINNNq (ORCPT ); Thu, 14 Sep 2006 09:13:46 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S932073AbWINNNq (ORCPT ); Thu, 14 Sep 2006 09:13:46 -0400 Received: from mail.sf-mail.de ([62.27.20.61]:64482 "EHLO mail.sf-mail.de") by vger.kernel.org with ESMTP id S932071AbWINNNo (ORCPT ); Thu, 14 Sep 2006 09:13:44 -0400 From: Rolf Eike Beer To: linux-kernel@vger.kernel.org Subject: "hard-safe -> hard-unsafe lock order detected" on rmmod Date: Thu, 14 Sep 2006 15:13:52 +0200 User-Agent: KMail/1.9.4 MIME-Version: 1.0 Content-Type: multipart/signed; boundary="nextPart1626601.oYr4kK8KYi"; protocol="application/pgp-signature"; micalg=pgp-sha1 Content-Transfer-Encoding: 7bit Message-Id: <200609141513.52932.eike-kernel@sf-tec.de> Sender: linux-kernel-owner@vger.kernel.org X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 43175 Lines: 880 --nextPart1626601.oYr4kK8KYi Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable Content-Disposition: inline I tried to clean up my modules list from all the stuff SuSE loaded on boot: rmmod dm_snapshot ohci_hcd snd_intel8x0 ide_cd ehci_hcd floppy ip6table_man= gle=20 iptable_nat iptable_mangle snd_seq snd_seq_device snd_pcm_oss edd Result was this: Result of uname -a Linux siso-rl-i34d 2.6.18-rc6 #38 SMP Tue Sep 5 16:14:22 CEST 2006 i686 i68= 6=20 i386 GNU/Linux =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D [ INFO: hard-safe -> hard-unsafe lock order detected ] =2D----------------------------------------------------- rmmod/5158 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: (proc_subdir_lock){--..}, at: [] remove_proc_entry+0x40/0x18b and this task is already holding: (ide_lock){++..}, at: [] ide_unregister_subdriver+0x38/0xc7 which would create a new lock dependency: (ide_lock){++..} -> (proc_subdir_lock){--..} but this new dependency connects a hard-irq-safe lock: (ide_lock){++..} =2E.. which became hard-irq-safe at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] ide_intr+0x18/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf to a hard-irq-unsafe lock: (proc_subdir_lock){--..} =2E.. which became hard-irq-unsafe at: =2E.. [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] xlate_proc_name+0x1b/0x99 [] proc_create+0x46/0xdf [] create_proc_entry+0x60/0xa3 [] proc_misc_init+0x1c/0x1b0 [] proc_root_init+0x4c/0xd1 [] start_kernel+0x279/0x391 [<00000000>] 0x0 other info that might help us debug this: 1 lock held by rmmod/5158: #0: (ide_lock){++..}, at: [] ide_unregister_subdriver+0x38/0xc7 the hard-irq-safe lock's dependencies: =2D> (ide_lock){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irq+0x1f/0x2e [] init_irq+0x2f5/0x43d [] hwif_init+0x100/0x25e [] probe_hwif_init_with_fixup+0x1d/0x75 [] ide_setup_pci_device+0x3e/0x71 [] amd74xx_probe+0x63/0x6a [amd74xx] [] pci_device_probe+0x39/0x59 [] driver_probe_device+0x45/0x98 [] __driver_attach+0x68/0x93 [] bus_for_each_dev+0x36/0x5b [] driver_attach+0x14/0x17 [] bus_add_driver+0x64/0xf3 [] driver_register+0x78/0x7d [] __pci_register_driver+0x4f/0x69 [] __ide_pci_register_driver+0x13/0x35 [] amd74xx_ide_init+0x12/0x14 [amd74xx] [] sys_init_module+0x16b6/0x17cf [] sysenter_past_esp+0x56/0x8d in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] ide_intr+0x18/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] ide_intr+0x18/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf } ... key at: [] ide_lock+0x10/0x80 -> (base_lock_keys + cpu){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] lock_timer_base+0x18/0x33 [] __mod_timer+0x26/0xac [] mod_timer+0x25/0x2b [] con_init+0xb6/0x1e7 [] console_init+0x1e/0x2c [] start_kernel+0x1bd/0x391 [<00000000>] 0x0 in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] lock_timer_base+0x18/0x33 [] del_timer+0x17/0x49 [] scsi_delete_timer+0xe/0x1f [] scsi_done+0xb/0x19 [] ata_scsi_qc_complete+0xb0/0xbd [] __ata_qc_complete+0x1b0/0x1b8 [] ata_qc_complete+0xa2/0xa9 [] ata_hsm_qc_complete+0x1b8/0x1c7 [] ata_hsm_move+0x690/0x6a6 [] ata_host_intr+0xad/0xc5 [] nv_do_interrupt+0x9a/0xdf [] nv_ck804_interrupt+0x21/0x30 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irq+0x1f/0x2e [] run_timer_softirq+0x3d/0x16e [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf } ... key at: [] base_lock_keys+0x0/0x40 ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] lock_timer_base+0x18/0x33 [] __mod_timer+0x26/0xac [] __ide_set_handler+0x59/0x61 [] ide_set_handler+0x29/0x3e [] cdrom_transfer_packet_command+0x76/0xcb [ide_cd] [] cdrom_do_pc_continuation+0x2e/0x31 [ide_cd] [] cdrom_start_packet_command+0x12f/0x137 [ide_cd] [] ide_do_rw_cdrom+0x455/0x494 [ide_cd] [] ide_do_request+0x521/0x682 [] do_ide_request+0x17/0x1a [] elv_insert+0x58/0x135 [] __elv_add_request+0x83/0x88 [] ide_do_drive_cmd+0xbf/0x10c [] cdrom_queue_packet_command+0x40/0xc6 [ide_cd] [] ide_cdrom_packet+0x86/0xa4 [ide_cd] [] cdrom_mode_sense+0x58/0x60 [cdrom] [] ide_cdrom_get_capabilities+0x7d/0x8d [ide_cd] [] ide_cd_probe+0x54a/0xa3b [ide_cd] [] generic_ide_probe+0x22/0x24 [] driver_probe_device+0x45/0x98 [] __driver_attach+0x68/0x93 [] bus_for_each_dev+0x36/0x5b [] driver_attach+0x14/0x17 [] bus_add_driver+0x64/0xf3 [] driver_register+0x78/0x7d [] ____versions+0x42d/0xfffffec3 [ip6_tables] [] sys_init_module+0x16b6/0x17cf [] sysenter_past_esp+0x56/0x8d -> (&input_pool.lock){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] account+0x35/0xcb [] extract_entropy+0x28/0x83 [] xfer_secondary_pool+0xc1/0xfa [] extract_entropy+0x18/0x83 [] get_random_bytes+0x15/0x19 [] neigh_table_init_no_netlink+0x103/0x= 1ba [] neigh_table_init+0xc/0x5f [] arp_init+0xd/0x62 [] inet_init+0x101/0x2cb [] init+0x114/0x293 [] kernel_thread_helper+0x5/0xb in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __add_entropy_words+0x4c/0x161 [] add_timer_randomness+0x6a/0x106 [] add_disk_randomness+0x26/0x28 [] ide_end_request+0x9e/0xd8 [] cdrom_end_request+0x10e/0x116 [ide_c= d] [] cdrom_pc_intr+0xc9/0x1f4 [ide_cd] [] ide_intr+0x147/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __add_entropy_words+0x4c/0x161 [] add_timer_randomness+0x6a/0x106 [] add_disk_randomness+0x26/0x28 [] scsi_end_request+0x62/0xa9 [] scsi_io_completion+0xf4/0x2bb [] sd_rw_intr+0x1c0/0x1c8 [] scsi_finish_command+0x42/0x47 [] scsi_softirq_done+0xab/0xb6 [] blk_done_softirq+0x5e/0x6d [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf } ... key at: [] input_pool+0x90/0x100 ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __add_entropy_words+0x4c/0x161 [] add_timer_randomness+0x6a/0x106 [] add_disk_randomness+0x26/0x28 [] ide_end_request+0x9e/0xd8 [] cdrom_end_request+0x10e/0x116 [ide_cd] [] cdrom_pc_intr+0xc9/0x1f4 [ide_cd] [] ide_intr+0x147/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf -> (random_read_wait.lock){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __wake_up+0x13/0x39 [] add_timer_randomness+0xfe/0x106 [] add_disk_randomness+0x26/0x28 [] scsi_end_request+0x62/0xa9 [] scsi_io_completion+0xf4/0x2bb [] sd_rw_intr+0x1c0/0x1c8 [] scsi_finish_command+0x42/0x47 [] scsi_softirq_done+0xab/0xb6 [] blk_done_softirq+0x5e/0x6d [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __wake_up+0x13/0x39 [] add_timer_randomness+0xfe/0x106 [] add_disk_randomness+0x26/0x28 [] ide_end_request+0x9e/0xd8 [] cdrom_end_request+0x10e/0x116 [ide_c= d] [] cdrom_pc_intr+0xc9/0x1f4 [ide_cd] [] ide_intr+0x147/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __wake_up+0x13/0x39 [] add_timer_randomness+0xfe/0x106 [] add_disk_randomness+0x26/0x28 [] scsi_end_request+0x62/0xa9 [] scsi_io_completion+0xf4/0x2bb [] sd_rw_intr+0x1c0/0x1c8 [] scsi_finish_command+0x42/0x47 [] scsi_softirq_done+0xab/0xb6 [] blk_done_softirq+0x5e/0x6d [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf } ... key at: [] random_read_wait+0x10/0x40 ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] __wake_up+0x13/0x39 [] add_timer_randomness+0xfe/0x106 [] add_disk_randomness+0x26/0x28 [] ide_end_request+0x9e/0xd8 [] cdrom_end_request+0x10e/0x116 [ide_cd] [] cdrom_pc_intr+0xc9/0x1f4 [ide_cd] [] ide_intr+0x147/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf -> (&q->lock){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irq+0x1f/0x2e [] wait_for_completion+0x29/0xb4 [] keventd_create_kthread+0x2b/0x57 [] kthread_create+0x7f/0xbc [] migration_call+0x2d/0xb0 [] migration_init+0x1f/0x3f [] init+0x3e/0x293 [] kernel_thread_helper+0x5/0xb in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] complete+0x12/0x3e [] ata_qc_complete_internal+0xe/0x10 [] __ata_qc_complete+0x1b0/0x1b8 [] ata_qc_complete+0xa2/0xa9 [] ata_hsm_qc_complete+0x1b8/0x1c7 [] ata_hsm_move+0x690/0x6a6 [] ata_host_intr+0xad/0xc5 [] nv_do_interrupt+0x9a/0xdf [] nv_ck804_interrupt+0x21/0x30 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] complete+0x12/0x3e [] wakeme_after_rcu+0xb/0xd [] __rcu_process_callbacks+0x113/0x172 [] rcu_process_callbacks+0x25/0x44 [] tasklet_action+0x65/0xca [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf } ... key at: [] __key.13301+0x0/0x8 -> (&rq->rq_lock_key){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] init_idle+0x5c/0x7a [] sched_init+0x173/0x179 [] start_kernel+0x113/0x391 [<00000000>] 0x0 in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] scheduler_tick+0x97/0x327 [] update_process_times+0x55/0x61 [] smp_local_timer_interrupt+0x2d/0x30 [] timer_interrupt+0x53/0x7b [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] task_rq_lock+0x34/0x5b [] try_to_wake_up+0x19/0x361 [] wake_up_process+0xf/0x11 [] __do_softirq+0xd4/0xee [] do_softirq+0x61/0xbf } ... key at: [] 0xc49aa7ec -> (&rq->rq_lock_key#2){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] init_idle+0x5c/0x7a [] fork_idle+0x3f/0x49 [] smp_boot_cpus+0x4e1/0xd21 [] smp_prepare_cpus+0x21/0x23 [] init+0x39/0x293 [] kernel_thread_helper+0x5/0xb in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] scheduler_tick+0x97/0x327 [] update_process_times+0x55/0x61 [] smp_apic_timer_interrupt+0x60/0x= 68 [] apic_timer_interrupt+0x2a/0x30 [] cpu_idle+0x61/0x77 [] start_secondary+0x3e8/0x3f3 [<00000000>] 0x0 [] 0xdfd0efb4 in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] task_rq_lock+0x34/0x5b [] try_to_wake_up+0x19/0x361 [] wake_up_process+0xf/0x11 [] __do_softirq+0xd4/0xee [] do_softirq+0x61/0xbf } ... key at: [] 0xc49b27ec ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] double_lock_balance+0x2f/0x33 [] schedule+0x24e/0x900 [] schedule_timeout+0x72/0x90 [] schedule_timeout_uninterruptible+0x18/0x1a [] journal_stop+0xda/0x1e1 [] journal_force_commit+0x1f/0x25 [] ext3_force_commit+0x22/0x24 [] ext3_write_inode+0x38/0x3e [] __writeback_single_inode+0x1bb/0x331 [] sync_inode+0x1c/0x2e [] ext3_sync_file+0xa1/0xb8 [] do_fsync+0x4a/0x7c [] __do_fsync+0x20/0x2f [] sys_fsync+0xd/0xf [] sysenter_past_esp+0x56/0x8d ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] task_rq_lock+0x34/0x5b [] try_to_wake_up+0x19/0x361 [] default_wake_function+0xb/0xd [] __wake_up_common+0x2f/0x53 [] complete+0x2b/0x3e [] kthread+0xa5/0xf0 [] kernel_thread_helper+0x5/0xb -> (&rq->rq_lock_key#2){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] init_idle+0x5c/0x7a [] fork_idle+0x3f/0x49 [] smp_boot_cpus+0x4e1/0xd21 [] smp_prepare_cpus+0x21/0x23 [] init+0x39/0x293 [] kernel_thread_helper+0x5/0xb in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] scheduler_tick+0x97/0x327 [] update_process_times+0x55/0x61 [] smp_apic_timer_interrupt+0x60/0x68 [] apic_timer_interrupt+0x2a/0x30 [] cpu_idle+0x61/0x77 [] start_secondary+0x3e8/0x3f3 [<00000000>] 0x0 [] 0xdfd0efb4 in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] task_rq_lock+0x34/0x5b [] try_to_wake_up+0x19/0x361 [] wake_up_process+0xf/0x11 [] __do_softirq+0xd4/0xee [] do_softirq+0x61/0xbf } ... key at: [] 0xc49b27ec ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [] task_rq_lock+0x34/0x5b [] try_to_wake_up+0x19/0x361 [] default_wake_function+0xb/0xd [] __wake_up_common+0x2f/0x53 [] complete+0x2b/0x3e [] migration_thread+0x210/0x236 [] kthread+0xc4/0xf0 [] kernel_thread_helper+0x5/0xb ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] complete+0x12/0x3e [] blk_end_sync_rq+0x1f/0x22 [] end_that_request_last+0xba/0xcd [] ide_end_request+0xbf/0xd8 [] cdrom_end_request+0x10e/0x116 [ide_cd] [] cdrom_pc_intr+0xc9/0x1f4 [ide_cd] [] ide_intr+0x147/0x1a7 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf -> (base_lock_keys + cpu#2){++..} ops: 0 { initial-use at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irq+0x1f/0x2e [] run_timer_softirq+0x3d/0x16e [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf in-hardirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irqsave+0x22/0x32 [] lock_timer_base+0x18/0x33 [] del_timer+0x17/0x49 [] scsi_delete_timer+0xe/0x1f [] scsi_done+0xb/0x19 [] ata_scsi_qc_complete+0xb0/0xbd [] __ata_qc_complete+0x1b0/0x1b8 [] ata_qc_complete+0xa2/0xa9 [] ata_hsm_qc_complete+0x1b8/0x1c7 [] ata_hsm_move+0x690/0x6a6 [] ata_host_intr+0xad/0xc5 [] nv_do_interrupt+0x9a/0xdf [] nv_ck804_interrupt+0x21/0x30 [] handle_IRQ_event+0x1f/0x4c [] __do_IRQ+0x94/0xef [] do_IRQ+0x9e/0xbf in-softirq-W at: [] lock_acquire+0x4a/0x6a [] _spin_lock_irq+0x1f/0x2e [] run_timer_softirq+0x3d/0x16e [] __do_softirq+0x76/0xee [] do_softirq+0x61/0xbf } ... key at: [] base_lock_keys+0x8/0x40 ... acquired at: [] lock_acquire+0x4a/0x6a [] _spin_lock+0x19/0x28 [