Cloned as F25 is going EOL and this affects F26. +++ This bug was initially created as a clone of Bug #1436866 +++ Description of problem: NFC: Reader power on cmd error -11 Version-Release number of selected component (if applicable): Card Reader ACR122U-A9 How reproducible: Plug usb connector's reader to usb port. Steps to Reproduce: 1.plug reader 2. 3. Actual results: [ 6292.358501] usb 1-2: New USB device found, idVendor=072f, idProduct=2200 [ 6292.358506] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 6292.358509] usb 1-2: Product: ACR122U PICC Interface [ 6292.358511] usb 1-2: Manufacturer: ACS [ 6292.450257] nfc: nfc_init: NFC Core ver 0.1 [ 6292.450297] NET: Registered protocol family 39 [ 6292.462827] ------------[ cut here ]------------ [ 6292.462841] WARNING: CPU: 3 PID: 6314 at drivers/usb/core/hcd.c:1584 usb_hcd_map_urb_for_dma+0x37f/0x570 [ 6292.462842] transfer buffer not dma capable [ 6292.462843] Modules linked in: pn533_usb(+) pn533 nfc rfcomm ccm xt_CHECKSUM ipt_MASQUERADE nf_nat_masquerade_ipv4 tun ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_broute bridge stp llc ebtable_nat ip6table_raw ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_security ip6table_mangle iptable_raw iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_security iptable_mangle ebtable_filter ebtables ip6table_filter ip6_tables vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) cmac bnep vboxdrv(OE) arc4 vfat fat tpm_crb iTCO_wdt i2c_designware_platform iTCO_vendor_support mei_wdt i2c_designware_core dell_wmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm uvcvideo irqbypass videobuf2_vmalloc videobuf2_memops [ 6292.462887] videobuf2_v4l2 crct10dif_pclmul videobuf2_core crc32_pclmul videodev ghash_clmulni_intel btusb media btrtl snd_hda_codec_hdmi dell_led dell_smbios dcdbas ath10k_pci ath10k_core mac80211 ath cfg80211 snd_hda_codec_realtek hci_uart snd_hda_codec_generic btbcm rtsx_pci_ms memstick btqca joydev btintel bluetooth snd_hda_intel snd_hda_codec snd_hda_core pinctrl_sunrisepoint snd_hwdep rfkill dell_smo8800 snd_seq pinctrl_intel snd_seq_device intel_hid i2c_i801 intel_lpss_acpi mei_me snd_pcm idma64 i2c_smbus sparse_keymap mei snd_timer shpchp processor_thermal_device snd int3400_thermal intel_lpss_pci soundcore acpi_thermal_rel intel_lpss intel_soc_dts_iosf tpm_tis acpi_als kfifo_buf tpm_tis_core industrialio tpm int3403_thermal int340x_thermal_zone acpi_pad nfsd auth_rpcgss nfs_acl lockd grace [ 6292.462935] sunrpc mmc_block hid_multitouch nouveau i915 rtsx_pci_sdmmc mmc_core mxm_wmi ttm i2c_algo_bit drm_kms_helper crc32c_intel drm nvme serio_raw rtsx_pci nvme_core i2c_hid video wmi fjes [ 6292.462951] CPU: 3 PID: 6314 Comm: systemd-udevd Tainted: G OE 4.9.14-200.fc25.x86_64 #1 [ 6292.462952] Hardware name: Dell Inc. XPS 15 9560/05FFDN, BIOS 1.0.3 01/09/2017 [ 6292.462957] ffffb59bc560b858 ffffffffa33f4cfd ffffb59bc560b8a8 0000000000000000 [ 6292.462962] ffffb59bc560b898 ffffffffa30a305b 0000063000000100 ffff9f372a4d6a80 [ 6292.462966] 0000000000000000 ffff9f3618d60000 0000000000000001 ffff9f372cfda000 [ 6292.462971] Call Trace: [ 6292.462987] [<ffffffffa33f4cfd>] dump_stack+0x63/0x86 [ 6292.462990] [<ffffffffa30a305b>] __warn+0xcb/0xf0 [ 6292.462992] [<ffffffffa30a30df>] warn_slowpath_fmt+0x5f/0x80 [ 6292.462998] [<ffffffffa341482d>] ? list_del+0xd/0x30 [ 6292.463001] [<ffffffffa35ed90f>] usb_hcd_map_urb_for_dma+0x37f/0x570 [ 6292.463004] [<ffffffffa35ee0fa>] usb_hcd_submit_urb+0x35a/0xb50 [ 6292.463007] [<ffffffffa33f56c2>] ? get_from_free_list+0x42/0x50 [ 6292.463008] [<ffffffffa33f6879>] ? ida_get_new_above+0x1e9/0x210 [ 6292.463011] [<ffffffffa35efaa4>] usb_submit_urb+0x2f4/0x560 [ 6292.463017] [<ffffffffa3230fff>] ? __kmalloc+0x16f/0x1f0 [ 6292.463019] [<ffffffffa35ef529>] ? usb_alloc_urb+0x19/0x50 [ 6292.463027] [<ffffffffc100f963>] pn533_usb_probe+0x353/0x4ff [pn533_usb] [ 6292.463031] [<ffffffffa35f4d69>] usb_probe_interface+0x159/0x2d0 [ 6292.463033] [<ffffffffa354c703>] driver_probe_device+0x223/0x430 [ 6292.463035] [<ffffffffa354c9ef>] __driver_attach+0xdf/0xf0 [ 6292.463037] [<ffffffffa354c910>] ? driver_probe_device+0x430/0x430 [ 6292.463045] [<ffffffffa354a0ec>] bus_for_each_dev+0x6c/0xc0 [ 6292.463047] [<ffffffffa354be4e>] driver_attach+0x1e/0x20 [ 6292.463050] [<ffffffffa354b880>] bus_add_driver+0x170/0x270 [ 6292.463052] [<ffffffffa354d310>] driver_register+0x60/0xe0 [ 6292.463054] [<ffffffffa35f3631>] usb_register_driver+0x81/0x140 [ 6292.463056] [<ffffffffc03b0000>] ? 0xffffffffc03b0000 [ 6292.463060] [<ffffffffc03b001e>] pn533_usb_driver_init+0x1e/0x1000 [pn533_usb] [ 6292.463065] [<ffffffffa3002190>] do_one_initcall+0x50/0x180 [ 6292.463069] [<ffffffffa322fbe9>] ? kmem_cache_alloc_trace+0x159/0x1b0 [ 6292.463077] [<ffffffffa31c07ea>] ? do_init_module+0x27/0x1ef [ 6292.463080] [<ffffffffa31c0822>] do_init_module+0x5f/0x1ef [ 6292.463084] [<ffffffffa3130231>] load_module+0x25b1/0x2980 [ 6292.463086] [<ffffffffa312cb10>] ? __symbol_put+0x60/0x60 [ 6292.463089] [<ffffffffa3130773>] SYSC_init_module+0x173/0x190 [ 6292.463091] [<ffffffffa31308ae>] SyS_init_module+0xe/0x10 [ 6292.463098] [<ffffffffa381dc77>] entry_SYSCALL_64_fastpath+0x1a/0xa9 [ 6292.463100] ---[ end trace fade6511ac15b696 ]--- [ 6292.463105] usb 1-2: NFC: Reader power on cmd error -11 [ 6292.463113] pn533_usb 1-2:1.0: NFC: Couldn't poweron the reader (error -11) [ 6292.463148] pn533_usb: probe of 1-2:1.0 failed with error -11 [ 6292.463231] usbcore: registered new interface driver pn533_usb [ 7467.722511] usb 1-2: USB disconnect, device number 6 [ 7470.541529] usb 1-1: USB disconnect, device number 2 [ 7475.893610] usb 1-1: new full-speed USB device number 7 using xhci_hcd [ 7476.065493] usb 1-1: New USB device found, idVendor=072f, idProduct=2200 [ 7476.065497] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 7476.065502] usb 1-1: Product: ACR122U PICC Interface [ 7476.065505] usb 1-1: Manufacturer: ACS [ 7476.066969] usb 1-1: NFC: Reader power on cmd error -11 [ 7476.066978] pn533_usb 1-1:1.0: NFC: Couldn't poweron the reader (error -11) [ 7476.066988] pn533_usb: probe of 1-1:1.0 failed with error -11 Expected results: Additional info: KERNEL VERSION 4.9.14-200.fc25.x86_64 --- Additional comment from Peter Schwindt on 2017-04-19 06:00:33 EDT --- Same result on 4.10.10-200.fc25.x86_64 --- Additional comment from Laura Abbott on 2017-05-05 11:47:52 EDT --- --- Additional comment from Till Maas on 2017-05-11 17:07:56 EDT --- bug 1415397 contains a patch to make a different driver DMA capable. Does this maybe help to develop a fix for this problem? --- Additional comment from Till Maas on 2017-05-11 17:09:59 EDT --- Just found two patches here: https://www.spinics.net/lists/linux-wireless/msg160806.html https://www.spinics.net/lists/linux-wireless/msg160914.html --- Additional comment from Till Maas on 2017-05-11 17:24:58 EDT --- kernel-4.10.15-200.fc25 fixes this bug for me --- Additional comment from Alex on 2017-11-13 06:29:18 EST --- This issue affects the latest kernel (4.13.11-200.fc26) and the one mentioned by the last commenter for me 4.13.5-200.fc26.x86_64 (albeit for f26 not 25) [root@blackbird Desktop]# uname -a Linux blackbird 4.13.5-200.fc26.x86_64 #1 SMP Thu Oct 5 16:53:13 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux [root@blackbird Desktop]# cat /etc/fedora-release Fedora release 26 (Twenty Six) [root@blackbird Desktop]# dmesg | egrep 17953 [17953.242031] usb 1-12: new full-speed USB device number 7 using xhci_hcd [17953.413512] usb 1-12: New USB device found, idVendor=072f, idProduct=2200 [17953.413517] usb 1-12: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [17953.413520] usb 1-12: Product: ACR122U PICC Interface [17953.413523] usb 1-12: Manufacturer: ACS [17953.475169] nfc: nfc_init: NFC Core ver 0.1 [17953.475211] NET: Registered protocol family 39 [17953.484319] transfer buffer not dma capable [17953.484333] ------------[ cut here ]------------ [17953.484339] WARNING: CPU: 1 PID: 1220 at drivers/usb/core/hcd.c:1595 usb_hcd_map_urb_for_dma+0x41d/0x620 [17953.484340] Modules linked in: pn533_usb(+) pn533 nfc bnep fuse tun ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables binfmt_misc sunrpc vfat fat snd_hda_codec_hdmi nvidia_drm(POE) nvidia_modeset(POE) intel_rapl x86_pkg_temp_thermal iTCO_wdt nvidia(POE) intel_powerclamp iTCO_vendor_support coretemp kvm_intel kvm snd_hda_codec_realtek snd_hda_codec_generic irqbypass intel_cstate intel_uncore snd_hda_intel intel_rapl_perf hci_uart snd_hda_codec snd_usb_audio drm_kms_helper [17953.484374] btbcm btqca snd_usbmidi_lib btintel snd_hda_core snd_rawmidi bluetooth snd_hwdep drm snd_seq snd_seq_device snd_pcm snd_timer snd mei_me mei joydev ecdh_generic soundcore intel_pch_thermal shpchp i2c_i801 rfkill tpm_infineon acpi_als intel_lpss_acpi tpm_tis kfifo_buf pinctrl_sunrisepoint tpm_tis_core industrialio tpm pinctrl_intel intel_lpss acpi_pad xfs libcrc32c dm_crypt uas usb_storage hid_microsoft mxm_wmi crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw alx mdio wmi video i2c_hid [17953.484403] CPU: 1 PID: 1220 Comm: systemd-udevd Tainted: P OE 4.13.5-200.fc26.x86_64 #1 [17953.484404] Hardware name: Gigabyte Technology Co., Ltd. Z170X-Gaming 3/Z170X-Gaming 3, BIOS F7 06/03/2016 [17953.484405] task: ffff95cae5f78000 task.stack: ffffb138ca514000 [17953.484408] RIP: 0010:usb_hcd_map_urb_for_dma+0x41d/0x620 [17953.484409] RSP: 0018:ffffb138ca5178e0 EFLAGS: 00010282 [17953.484411] RAX: 000000000000001f RBX: ffff95cae734e000 RCX: 0000000000000000 [17953.484412] RDX: 0000000000000000 RSI: ffff95cbb5c4e118 RDI: ffff95cbb5c4e118 [17953.484413] RBP: ffffb138ca517920 R08: 00000000000005e0 R09: 0000000000000004 [17953.484414] R10: 00000000001fffff R11: 0000000000000001 R12: 00000000fffffff5 [17953.484415] R13: 00000000014000c0 R14: 0000000000000001 R15: ffff95cb8fb7e000 [17953.484417] FS: 00007fa7128ae8c0(0000) GS:ffff95cbb5c40000(0000) knlGS:0000000000000000 [17953.484418] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [17953.484419] CR2: 000055d6a40e5000 CR3: 00000007a723b000 CR4: 00000000003406e0 [17953.484420] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [17953.484421] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [17953.484422] Call Trace: [17953.484427] usb_hcd_submit_urb+0x493/0xb40 [17953.484430] ? find_next_zero_bit+0x10/0x20 [17953.484433] ? ida_get_new_above+0x110/0x320 [17953.484434] ? find_next_zero_bit+0x10/0x20 [17953.484438] usb_submit_urb+0x22d/0x560 [17953.484442] pn533_usb_probe+0x3a3/0x4d2 [pn533_usb] [17953.484445] usb_probe_interface+0x124/0x300 [17953.484448] driver_probe_device+0x2ff/0x450 [17953.484450] __driver_attach+0xa4/0xe0 [17953.484452] ? driver_probe_device+0x450/0x450 [17953.484454] bus_for_each_dev+0x6e/0xb0 [17953.484456] driver_attach+0x1e/0x20 [17953.484458] bus_add_driver+0x1c7/0x270 [17953.484460] driver_register+0x60/0xe0 [17953.484462] usb_register_driver+0x81/0x150 [17953.484464] ? 0xffffffffc0074000 [17953.484467] pn533_usb_driver_init+0x1e/0x1000 [pn533_usb] [17953.484470] do_one_initcall+0x50/0x190 [17953.484473] ? kmem_cache_alloc_trace+0x15f/0x1c0 [17953.484475] ? do_init_module+0x27/0x1e9 [17953.484477] do_init_module+0x5f/0x1e9 [17953.484479] load_module+0x2602/0x2c30 [17953.484483] SYSC_init_module+0x170/0x1a0 [17953.484484] ? SYSC_init_module+0x170/0x1a0 [17953.484487] SyS_init_module+0xe/0x10 [17953.484489] do_syscall_64+0x67/0x140 [17953.484492] entry_SYSCALL64_slow_path+0x25/0x25 [17953.484493] RIP: 0033:0x7fa71152418a [17953.484494] RSP: 002b:00007ffcddcf0718 EFLAGS: 00000246 ORIG_RAX: 00000000000000af [17953.484496] RAX: ffffffffffffffda RBX: 000055d6a3fb5ec0 RCX: 00007fa71152418a [17953.484497] RDX: 00007fa71205a9c5 RSI: 000000000000452b RDI: 000055d6a3fb83f0 [17953.484497] RBP: 00007fa71205a9c5 R08: 000055d6a3fb5d80 R09: 0000000000000190 [17953.484498] R10: 00007fa7117deb00 R11: 0000000000000246 R12: 000055d6a3fb83f0 [17953.484499] R13: 000055d6a3fb5e60 R14: 0000000000020000 R15: 000055d6a3008f4a [17953.484501] Code: 48 39 c8 73 30 80 3d 99 64 9d 00 00 41 bc f5 ff ff ff 0f 85 26 ff ff ff 48 c7 c7 40 6a d0 98 c6 05 7f 64 9d 00 01 e8 04 42 ad ff <0f> ff 8b 53 64 e9 09 ff ff ff 65 48 8b 0c 25 00 d3 00 00 48 8b [17953.484534] ---[ end trace 2b5f1bdeb4b2936d ]--- [17953.484538] usb 1-12: NFC: Reader power on cmd error -11 [17953.484542] pn533_usb 1-12:1.0: NFC: Couldn't poweron the reader (error -11) [17953.484549] pn533_usb: probe of 1-12:1.0 failed with error -11 [PUA@blackbird Desktop]$ cat /etc/fedora-release Fedora release 26 (Twenty Six) [PUA@blackbird Desktop]$ uname -a Linux blackbird 4.13.11-200.fc26.x86_64 #1 SMP Thu Nov 2 18:28:35 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux [PUA@blackbird Desktop]$ dmesg | egrep "\[\s+6[21]\." [ 61.834242] usb 1-12: new full-speed USB device number 7 using xhci_hcd [ 62.006034] usb 1-12: New USB device found, idVendor=072f, idProduct=2200 [ 62.006039] usb 1-12: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 62.006042] usb 1-12: Product: ACR122U PICC Interface [ 62.006045] usb 1-12: Manufacturer: ACS [ 62.039644] nfc: nfc_init: NFC Core ver 0.1 [ 62.039654] NET: Registered protocol family 39 [ 62.042710] transfer buffer not dma capable [ 62.042717] ------------[ cut here ]------------ [ 62.042720] WARNING: CPU: 5 PID: 2311 at drivers/usb/core/hcd.c:1595 usb_hcd_map_urb_for_dma+0x41d/0x620 [ 62.042720] Modules linked in: pn533_usb(+) pn533 nfc bnep fuse tun ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables binfmt_misc sunrpc vfat fat snd_hda_codec_hdmi nvidia_drm(POE) nvidia_modeset(POE) intel_rapl nvidia(POE) x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support irqbypass intel_cstate intel_uncore snd_hda_codec_realtek snd_hda_codec_generic intel_rapl_perf snd_hda_intel snd_hda_codec snd_usb_audio hci_uart drm_kms_helper [ 62.042734] btbcm snd_hda_core btqca snd_usbmidi_lib btintel snd_hwdep snd_rawmidi snd_seq snd_seq_device bluetooth snd_pcm drm snd_timer snd joydev mei_me intel_pch_thermal tpm_infineon i2c_i801 mei soundcore shpchp tpm_tis tpm_tis_core ecdh_generic rfkill tpm pinctrl_sunrisepoint acpi_als pinctrl_intel intel_lpss_acpi kfifo_buf intel_lpss industrialio acpi_pad xfs libcrc32c dm_crypt uas usb_storage hid_microsoft crct10dif_pclmul mxm_wmi crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw alx mdio wmi video i2c_hid [ 62.042746] CPU: 5 PID: 2311 Comm: systemd-udevd Tainted: P OE 4.13.11-200.fc26.x86_64 #1 [ 62.042746] Hardware name: Gigabyte Technology Co., Ltd. Z170X-Gaming 3/Z170X-Gaming 3, BIOS F7 06/03/2016 [ 62.042747] task: ffff8d469d024d80 task.stack: ffff98d104294000 [ 62.042748] RIP: 0010:usb_hcd_map_urb_for_dma+0x41d/0x620 [ 62.042748] RSP: 0018:ffff98d1042978e0 EFLAGS: 00010282 [ 62.042749] RAX: 000000000000001f RBX: ffff8d46a47a5cc0 RCX: 0000000000000000 [ 62.042750] RDX: 0000000000000000 RSI: ffff8d46f5d4e118 RDI: ffff8d46f5d4e118 [ 62.042750] RBP: ffff98d104297920 R08: 0000000000000452 R09: 0000000000000004 [ 62.042750] R10: 00000000001fffff R11: 0000000000000001 R12: 00000000fffffff5 [ 62.042751] R13: 00000000014000c0 R14: 0000000000000001 R15: ffff8d46d1bf8000 [ 62.042752] FS: 00007f01752e78c0(0000) GS:ffff8d46f5d40000(0000) knlGS:0000000000000000 [ 62.042752] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 62.042752] CR2: 00005630e8df8000 CR3: 000000082fee9000 CR4: 00000000003406e0 [ 62.042753] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 62.042753] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 62.042754] Call Trace: [ 62.042756] usb_hcd_submit_urb+0x493/0xb40 [ 62.042758] ? find_next_zero_bit+0x10/0x20 [ 62.042759] ? ida_get_new_above+0x110/0x320 [ 62.042760] ? find_next_zero_bit+0x10/0x20 [ 62.042761] usb_submit_urb+0x22d/0x560 [ 62.042763] pn533_usb_probe+0x3a3/0x4d2 [pn533_usb] [ 62.042764] usb_probe_interface+0x124/0x300 [ 62.042766] driver_probe_device+0x2ff/0x450 [ 62.042767] __driver_attach+0xa4/0xe0 [ 62.042767] ? driver_probe_device+0x450/0x450 [ 62.042768] bus_for_each_dev+0x6e/0xb0 [ 62.042769] driver_attach+0x1e/0x20 [ 62.042770] bus_add_driver+0x1c7/0x270 [ 62.042771] driver_register+0x60/0xe0 [ 62.042772] usb_register_driver+0x81/0x150 [ 62.042772] ? 0xffffffffc0328000 [ 62.042774] pn533_usb_driver_init+0x1e/0x1000 [pn533_usb] [ 62.042775] do_one_initcall+0x50/0x190 [ 62.042777] ? kmem_cache_alloc_trace+0x15f/0x1c0 [ 62.042778] ? do_init_module+0x27/0x1e9 [ 62.042778] do_init_module+0x5f/0x1e9 [ 62.042779] load_module+0x2602/0x2c30 [ 62.042781] SYSC_init_module+0x170/0x1a0 [ 62.042781] ? SYSC_init_module+0x170/0x1a0 [ 62.042782] SyS_init_module+0xe/0x10 [ 62.042783] do_syscall_64+0x67/0x140 [ 62.042785] entry_SYSCALL64_slow_path+0x25/0x25 [ 62.042785] RIP: 0033:0x7f0173f5a3ea [ 62.042786] RSP: 002b:00007ffc61225048 EFLAGS: 00000246 ORIG_RAX: 00000000000000af [ 62.042786] RAX: ffffffffffffffda RBX: 00005630e8ccc6d0 RCX: 00007f0173f5a3ea [ 62.042787] RDX: 00007f0174a949c5 RSI: 000000000000452b RDI: 00005630e8cf8970 [ 62.042787] RBP: 00007f0174a949c5 R08: 00005630e8cbe410 R09: 00000000000000e0 [ 62.042787] R10: 00007f0174218b00 R11: 0000000000000246 R12: 00005630e8cf8970 [ 62.042788] R13: 00005630e8cec6e0 R14: 0000000000020000 R15: 00005630e85f3df7 [ 62.042788] Code: 48 39 c8 73 30 80 3d 19 61 9d 00 00 41 bc f5 ff ff ff 0f 85 26 ff ff ff 48 c7 c7 60 6d d0 be c6 05 ff 60 9d 00 01 e8 44 3d ad ff <0f> ff 8b 53 64 e9 09 ff ff ff 65 48 8b 0c 25 00 d3 00 00 48 8b [ 62.042802] ---[ end trace 4c9867f5fa811b1e ]--- [ 62.042804] usb 1-12: NFC: Reader power on cmd error -11 [ 62.042805] pn533_usb 1-12:1.0: NFC: Couldn't poweron the reader (error -11) [ 62.042808] pn533_usb: probe of 1-12:1.0 failed with error -11 [ 62.042815] usbcore: registered new interface driver pn533_usb --- Additional comment from Fedora End Of Life on 2017-11-16 10:44:40 EST --- [SNIP]
We apologize for the inconvenience. There is a large number of bugs to go through and several of them have gone stale. The kernel moves very fast so bugs may get fixed as part of a kernel update. Due to this, we are doing a mass bug update across all of the Fedora 26 kernel bugs. Fedora 26 has now been rebased to 4.15.4-200.fc26. Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel. If you have moved on to Fedora 27, and are still experiencing this issue, please change the version to Fedora 27. If you experience different issues, please open a new bug report for those.
This issue affects kernels up to and including 4.15.4-300.fc27.x86_64
Created attachment 1402441 [details] [PATCH] NFC: pn533: use kmalloc-ed memory for USB transfer buffers Here is a patch which should fix the error about the buffer not being dma capable, not sure if this will also fix the actual -11 / -EAGAIN error though.
Here is a test-build of the latest Fedora kernel with the patch added: https://koji.fedoraproject.org/koji/taskinfo?taskID=25388155 Note this is still building atm (this takes a couple of hours), for instructions for testing a kernel directly from koji, see: https://fedorapeople.org/~jwrdegoede/kernel-test-instructions.txt Please let me know if this fixes the warning/backtrace, if it does then I will submit this upstream.
Thank you for the Patch Hans. Sadly it does not work: [ 174.319983] usb 1-4: new full-speed USB device number 8 using xhci_hcd [ 174.919606] usb 1-4: New USB device found, idVendor=072f, idProduct=2200 [ 174.919616] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 174.919623] usb 1-4: Product: ACR122U PICC Interface [ 174.919629] usb 1-4: Manufacturer: ACS [ 175.003330] nfc: nfc_init: NFC Core ver 0.1 [ 175.003451] NET: Registered protocol family 39 [ 175.014639] ================================ [ 175.014640] WARNING: inconsistent lock state [ 175.014642] 4.16.0-0.rc3.git2.1.rhbz1514134.fc29.x86_64 #1 Not tainted [ 175.014643] -------------------------------- [ 175.014644] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. [ 175.014646] systemd-logind/1497 [HC1[1]:SC0[0]:HE0:SE1] takes: [ 175.014647] (fs_reclaim){?.+.}, at: [<000000009a6be840>] fs_reclaim_acquire.part.75+0x5/0x30 [ 175.014654] {HARDIRQ-ON-W} state was registered at: [ 175.014655] irq event stamp: 1633158 [ 175.014658] hardirqs last enabled at (1633157): [<000000000a724ee0>] __raw_spin_lock_init+0x1c/0x50 [ 175.014662] hardirqs last disabled at (1633158): [<0000000003684e0b>] interrupt_entry+0xca/0xe0 [ 175.014664] softirqs last enabled at (1632674): [<000000006caec4fc>] __do_softirq+0x38c/0x4f7 [ 175.014666] softirqs last disabled at (1632565): [<00000000bfa17845>] irq_exit+0x101/0x110 [ 175.014667] other info that might help us debug this: [ 175.014669] Possible unsafe locking scenario: [ 175.014670] CPU0 [ 175.014672] ---- [ 175.014673] lock(fs_reclaim); [ 175.014675] <Interrupt> [ 175.014676] lock(fs_reclaim); [ 175.014678] *** DEADLOCK *** [ 175.014681] 1 lock held by systemd-logind/1497: [ 175.014682] #0: (kn->count#183){.+.+}, at: [<0000000093f616c1>] kernfs_fop_open+0x3a/0x410 [ 175.014688] stack backtrace: [ 175.014690] CPU: 2 PID: 1497 Comm: systemd-logind Not tainted 4.16.0-0.rc3.git2.1.rhbz1514134.fc29.x86_64 #1 [ 175.014692] Hardware name: LENOVO 20HGS22D1A/20HGS22D1A, BIOS N1WET41W (1.20 ) 10/17/2017 [ 175.014693] Call Trace: [ 175.014695] <IRQ> [ 175.014699] dump_stack+0x85/0xbf [ 175.014703] print_usage_bug.cold.59+0x1a8/0x1e2 [ 175.014706] print_shortest_lock_dependencies+0x40/0x40 [ 175.014709] ? mark_lock+0x51a/0x620 [ 175.014712] ? check_usage_backwards+0x130/0x130 [ 175.014715] ? __lock_acquire+0x776/0x16d0 [ 175.014718] ? __lock_acquire+0x29a/0x16d0 [ 175.014721] ? native_sched_clock+0x3e/0xa0 [ 175.014725] ? lock_acquire+0x9e/0x1b0 [ 175.014727] ? fs_reclaim_acquire.part.75+0x5/0x30 [ 175.014731] ? fs_reclaim_acquire.part.75+0x29/0x30 [ 175.014733] ? fs_reclaim_acquire.part.75+0x5/0x30 [ 175.014736] ? kmem_cache_alloc_node+0x34/0x330 [ 175.014738] ? __alloc_skb+0x57/0x1e0 [ 175.014740] ? __alloc_skb+0x57/0x1e0 [ 175.014743] ? __usb_hcd_giveback_urb+0x60/0x160 [ 175.014748] ? pn533_recv_response+0x4a/0xa0 [pn533_usb] [ 175.014751] ? __usb_hcd_giveback_urb+0x88/0x160 [ 175.014754] ? xhci_giveback_urb_in_irq.isra.38+0x87/0x1a0 [ 175.014756] ? inc_deq+0x15c/0x1c0 [ 175.014759] ? xhci_td_cleanup+0xfb/0x160 [ 175.014762] ? xhci_irq+0xaa0/0x2110 [ 175.014765] ? __lock_is_held+0x5a/0xa0 [ 175.014769] ? __handle_irq_event_percpu+0x46/0x320 [ 175.014772] ? handle_irq_event_percpu+0x30/0x80 [ 175.014775] ? handle_irq_event+0x34/0x51 [ 175.014778] ? handle_edge_irq+0x7b/0x190 [ 175.014780] ? handle_irq+0xbf/0x100 [ 175.014782] ? do_IRQ+0x53/0x110 [ 175.014785] ? common_interrupt+0xf/0xf [ 175.014786] </IRQ> [ 175.014789] ? kernfs_fop_open+0x1ee/0x410 [ 175.014791] ? kernfs_fop_open+0x1ee/0x410 [ 175.014794] ? lock_is_held_type+0x46/0x60 [ 175.014798] ? ___might_sleep+0x116/0x180 [ 175.014801] ? __mutex_lock+0x56/0xa10 [ 175.014803] ? mark_held_locks+0x57/0x80 [ 175.014805] ? __raw_spin_lock_init+0x1c/0x50 [ 175.014808] ? __lockdep_init_map+0x45/0x170 [ 175.014811] ? kernfs_fop_open+0x1ee/0x410 [ 175.014813] ? kernfs_fop_open+0x1ee/0x410 [ 175.014816] ? kernfs_fop_release+0x90/0x90 [ 175.014819] ? do_dentry_open+0x1c4/0x310 [ 175.014822] ? path_openat+0x512/0xfb0 [ 175.014826] ? do_filp_open+0x93/0x100 [ 175.014830] ? _raw_spin_unlock+0x24/0x30 [ 175.014833] ? do_sys_open+0x18a/0x210 [ 175.014837] ? do_syscall_64+0x79/0x210 [ 175.014840] ? entry_SYSCALL_64_after_hwframe+0x42/0xb7 [ 175.014844] BUG: sleeping function called from invalid context at mm/slab.h:420 [ 175.014846] in_atomic(): 1, irqs_disabled(): 1, pid: 1497, name: systemd-logind [ 175.014849] INFO: lockdep is turned off. [ 175.014851] irq event stamp: 1633158 [ 175.014854] hardirqs last enabled at (1633157): [<000000000a724ee0>] __raw_spin_lock_init+0x1c/0x50 [ 175.014857] hardirqs last disabled at (1633158): [<0000000003684e0b>] interrupt_entry+0xca/0xe0 [ 175.014861] softirqs last enabled at (1632674): [<000000006caec4fc>] __do_softirq+0x38c/0x4f7 [ 175.014864] softirqs last disabled at (1632565): [<00000000bfa17845>] irq_exit+0x101/0x110 [ 175.014867] CPU: 2 PID: 1497 Comm: systemd-logind Not tainted 4.16.0-0.rc3.git2.1.rhbz1514134.fc29.x86_64 #1 [ 175.014869] Hardware name: LENOVO 20HGS22D1A/20HGS22D1A, BIOS N1WET41W (1.20 ) 10/17/2017 [ 175.014871] Call Trace: [ 175.014873] <IRQ> [ 175.014876] dump_stack+0x85/0xbf [ 175.014880] ___might_sleep.cold.72+0xac/0xbc [ 175.014884] ? kmem_cache_alloc_node+0x26e/0x330 [ 175.014887] ? __alloc_skb+0x57/0x1e0 [ 175.014890] ? __alloc_skb+0x57/0x1e0 [ 175.014893] ? __usb_hcd_giveback_urb+0x60/0x160 [ 175.014897] ? pn533_recv_response+0x4a/0xa0 [pn533_usb] [ 175.014900] ? __usb_hcd_giveback_urb+0x88/0x160 [ 175.014904] ? xhci_giveback_urb_in_irq.isra.38+0x87/0x1a0 [ 175.014907] ? inc_deq+0x15c/0x1c0 [ 175.014910] ? xhci_td_cleanup+0xfb/0x160 [ 175.014914] ? xhci_irq+0xaa0/0x2110 [ 175.014918] ? __lock_is_held+0x5a/0xa0 [ 175.014923] ? __handle_irq_event_percpu+0x46/0x320 [ 175.014927] ? handle_irq_event_percpu+0x30/0x80 [ 175.014930] ? handle_irq_event+0x34/0x51 [ 175.014934] ? handle_edge_irq+0x7b/0x190 [ 175.014937] ? handle_irq+0xbf/0x100 [ 175.014940] ? do_IRQ+0x53/0x110 [ 175.014943] ? common_interrupt+0xf/0xf [ 175.014945] </IRQ> [ 175.014949] ? kernfs_fop_open+0x1ee/0x410 [ 175.014952] ? kernfs_fop_open+0x1ee/0x410 [ 175.014956] ? lock_is_held_type+0x46/0x60 [ 175.014960] ? ___might_sleep+0x116/0x180 [ 175.014964] ? __mutex_lock+0x56/0xa10 [ 175.014967] ? mark_held_locks+0x57/0x80 [ 175.014970] ? __raw_spin_lock_init+0x1c/0x50 [ 175.014974] ? __lockdep_init_map+0x45/0x170 [ 175.014979] ? kernfs_fop_open+0x1ee/0x410 [ 175.014981] ? kernfs_fop_open+0x1ee/0x410 [ 175.014985] ? kernfs_fop_release+0x90/0x90 [ 175.014988] ? do_dentry_open+0x1c4/0x310 [ 175.014992] ? path_openat+0x512/0xfb0 [ 175.014997] ? do_filp_open+0x93/0x100 [ 175.015004] ? _raw_spin_unlock+0x24/0x30 [ 175.015008] ? do_sys_open+0x18a/0x210 [ 175.015013] ? do_syscall_64+0x79/0x210 [ 175.015017] ? entry_SYSCALL_64_after_hwframe+0x42/0xb7 [ 175.017242] usb 1-4: NFC: NXP PN532 firmware ver 1.4 now attached [ 175.025360] usbcore: registered new interface driver pn533_usb
Ah, but we are making progress. We are getting much further then before, the driver now causes the kernel to complain about another driver bug then the first one I fixed, but it does register the NFC device. Fixing the second warning / issue is quite doable too, here is a new scratch build with the original fix + a second fix for the new issue: https://koji.fedoraproject.org/koji/taskinfo?taskID=25498501 As before this is still building atm (this takes a couple of hours), for instructions for testing a kernel directly from koji, see: https://fedorapeople.org/~jwrdegoede/kernel-test-instructions.txt
It seems that the backtraces are gone but it also seems to me that the reader is not working anymore. I will do further tests and report back.
(In reply to Till Maas from comment #7) > It seems that the backtraces are gone but it also seems to me that the > reader is not working anymore. I will do further tests and report back. Yes, I tested again. The reader works with an older kernel but not with the patched kernel. The backtrace is gone with the newer kernel. The older kernel still shows the backtrace but the reader works nonetheless.
Hi, (In reply to Till Maas from comment #8) > (In reply to Till Maas from comment #7) > > It seems that the backtraces are gone but it also seems to me that the > > reader is not working anymore. I will do further tests and report back. > > Yes, I tested again. The reader works with an older kernel but not with the > patched kernel. The backtrace is gone with the newer kernel. The older > kernel still shows the backtrace but the reader works nonetheless. What is the version of the older kernel? Regards, Hans
(In reply to Hans de Goede from comment #9) > What is the version of the older kernel? vmlinuz-4.15.7-300.fc27.x86_64
(In reply to Till Maas from comment #10) > vmlinuz-4.15.7-300.fc27.x86_64 Hmm, that is not that old. I can backport my fixes to that kernel and see if there are any unrelated changes in 4.16 which cause things to break there. But before I spend time on that, in your original bug report there were 2 issues really: 1) The "WARNING:" + backtrace 2) These errors, which are unrelated to the warning: [ 62.042804] usb 1-12: NFC: Reader power on cmd error -11 [ 62.042805] pn533_usb 1-12:1.0: NFC: Couldn't poweron the reader (error -11) [ 62.042808] pn533_usb: probe of 1-12:1.0 failed with error -11 With my first test kernel not only 1) got replaced by another "WARNING:" + backtrace, but 2) completely went away, which is somewhat weird. So maybe 2) is an intermittent error which only happens sometime. Can you retry with my second test kernel (which fixes both warnings) and: a) Check if it fails all the time, not just sometime b) Check for errors like those from 2) above in dmesg
(In reply to Hans de Goede from comment #11) > (In reply to Till Maas from comment #10) > > vmlinuz-4.15.7-300.fc27.x86_64 > > Hmm, that is not that old. I can backport my fixes to that kernel and see if > there are any unrelated changes in 4.16 which cause things to break there. > > But before I spend time on that, in your original bug report there were 2 > issues really: > > 1) The "WARNING:" + backtrace > > 2) These errors, which are unrelated to the warning: > [ 62.042804] usb 1-12: NFC: Reader power on cmd error -11 > [ 62.042805] pn533_usb 1-12:1.0: NFC: Couldn't poweron the reader (error > -11) > [ 62.042808] pn533_usb: probe of 1-12:1.0 failed with error -11 > > With my first test kernel not only 1) got replaced by another "WARNING:" + > backtrace, but 2) completely went away, which is somewhat weird. According to my old comment, kernel-4.10.15-200.fc25 already allowed me to use the reader again but at least the WARNING/backtrace kept happening. I am not sure about 2). > So maybe 2) is an intermittent error which only happens sometime. Can you > retry with my second test kernel (which fixes both warnings) and: > > a) Check if it fails all the time, not just sometime I tried several times, it failed. The reader's LED did not properly light up, even. > b) Check for errors like those from 2) above in dmesg I will do this later.
I have a different datapoint that I could obtain easier, with 4.14.11-200.fc26.x86_64 I get this dmesg output: [ +1.321390] usb 4-3: new full-speed USB device number 15 using ohci-pci [ +1.146027] usb 4-3: New USB device found, idVendor=072f, idProduct=2200 [ +0.000004] usb 4-3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ +0.000001] usb 4-3: Product: ACR122U PICC Interface [ +0.000002] usb 4-3: Manufacturer: ACS [ +0.002452] usb 4-3: NFC: Reader power on cmd error -11 [ +0.000007] pn533_usb 4-3:1.0: NFC: Couldn't poweron the reader (error -11) [ +0.000008] pn533_usb: probe of 4-3:1.0 failed with error -11 Currently I have to restart pcscd sometimes but then the reader works. Did not see the backtrace there.
I tested again with the second debug kernel. The reader does not work. Here are the details that I found so far: Kernel: 4.16.0-0.rc3.git2.1.rhbz1514134.fc29.x86_64 dmesg: [ +7,784675] usb 1-1: new full-speed USB device number 9 using xhci_hcd [ +0,533594] usb 1-1: New USB device found, idVendor=072f, idProduct=2200 [ +0,000011] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ +0,000008] usb 1-1: Product: ACR122U PICC Interface [ +0,000007] usb 1-1: Manufacturer: ACS [ +0,053183] nfc: nfc_init: NFC Core ver 0.1 [ +0,000137] NET: Registered protocol family 39 [ +0,011706] usb 1-1: NFC: NXP PN532 firmware ver 1.4 now attached [ +0,011307] usbcore: registered new interface driver pn533_usb journalctl -u pcscd: Mär 14 11:04:22 systemd[1]: Started PC/SC Smart Card Daemon. Mär 14 11:04:22 pcscd[4143]: 00000000 ccid_usb.c:649:OpenUSBByName() Can't claim interface 1/9: LIBUSB_ERROR_BUSY Mär 14 11:04:22 pcscd[4143]: 00000188 ifdhandler.c:150:CreateChannelByNameOrChannel() failed Mär 14 11:04:22 pcscd[4143]: 00000025 readerfactory.c:1105:RFInitializeReader() Open Port 0x200000 Failed (usb:072f/2200:libudev:0:/dev/bus/usb/001/009) Mär 14 11:04:22 pcscd[4143]: 00000005 readerfactory.c:376:RFAddReader() ACS ACR122U PICC Interface init failed. Mär 14 11:04:22 pcscd[4143]: 00000083 hotplug_libudev.c:523:HPAddDevice() Failed adding USB device: ACS ACR122U PICC Interface selinux (permissive mode): type=AVC msg=audit(1521022312.109:338): avc: denied { module_request } for pid=4926 comm="systemd-rfkill" kmod=6E65746465762DE3C452F76C55 scontext=system_u:system_r:systemd_rfkill_t:s0 tcontext=system_u:system_r:kernel_t:s0 tclass=system permissive=1
Hi, Ah, so pcscd wants to talk directly to the usb-interface and the problem is that my fixes make the driver actually bind to it as its supposed to, so now the interface is busy. The kernel does allow unbinding drivers and libusb does have an interface for this, so the remaining problem seems to be a pcscd bug. Try the following: ls /sys/bus/usb/drivers/pn533_usb You should see a symlink in there which looks something like "1-1:1.0" but then possibly with different numbers *and* possibly also longer e.g. it might also look like "1-9.4.1:1.2". Now do: sudo sh -c "echo '1-1:1.0' > /sys/bus/usb/drivers/pn533_usb/unbind Replacing '1-1:1.0' with the device-identifier for the reader on your system and after that restart pcscd, that should allow it to bind to the interface. So it seems that by fixing the driver I actually broke things for you as now the driver is binding successfully and thus gets in the way of pcscd. If my theory on this is right, please file a new bug against pcscd for this. Please also file an upstream bug for this and add the following comment on both down and upstream bugs: "Recent versions of libusb have a new: libusb_set_auto_detach_kernel_driver() api which pcscd should call on the libusb_device_handle for the device before trying to claim interfaces, libusb will then automatically detech the kernel driver on claiming the interface (if necessary) and re-attach it on releasing the interface." Regards, Hans
awesome, thank you. The new bug is #1555264
bug 1555264
*********** MASS BUG UPDATE ************** We apologize for the inconvenience. There are a large number of bugs to go through and several of them have gone stale. Due to this, we are doing a mass bug update across all of the Fedora 27 kernel bugs. Fedora 27 has now been rebased to 4.17.7-100.fc27. Please test this kernel update (or newer) and let us know if you issue has been resolved or if it is still present with the newer kernel. If you have moved on to Fedora 28, and are still experiencing this issue, please change the version to Fedora 28. If you experience different issues, please open a new bug report for those.
*********** MASS BUG UPDATE ************** This bug is being closed with INSUFFICIENT_DATA as there has not been a response in 5 weeks. If you are still experiencing this issue, please reopen and attach the relevant data from the latest kernel you are running and any data that might have been requested previously.