From owner-freebsd-usb@FreeBSD.ORG Thu Jul 28 17:20:19 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 6FBC316A41F for ; Thu, 28 Jul 2005 17:20:19 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 990C643D45 for ; Thu, 28 Jul 2005 17:20:18 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j6SHKIhK034932 for ; Thu, 28 Jul 2005 17:20:18 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j6SHKIvj034931; Thu, 28 Jul 2005 17:20:18 GMT (envelope-from gnats) Date: Thu, 28 Jul 2005 17:20:18 GMT Message-Id: <200507281720.j6SHKIvj034931@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Janos Mohacsi Cc: Subject: Re: usb/83863: Communication problem between opensc/openct via USB with e-gate smart-card. X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Janos Mohacsi List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 28 Jul 2005 17:20:19 -0000 The following reply was made to PR usb/83863; it has been noted by GNATS. From: Janos Mohacsi To: bug-followup@FreeBSD.org, janos.mohacsi@bsd.hu, hselasky@c2i.net Cc: Subject: Re: usb/83863: Communication problem between opensc/openct via USB with e-gate smart-card. Date: Thu, 28 Jul 2005 19:12:59 +0200 Here I send several debuging output. relevant part of /var/log/debug: Jul 28 19:01:54 scone ifdhandler[71277]: ifd_open: trying to open egate@/dev/ugen0 Jul 28 19:01:54 scone ifdhandler[71277]: eg_open: device=/dev/ugen0 Jul 28 19:01:54 scone ifdhandler[71277]: ifd_sysdep_device_type: BSD: ifd_sysdep_device_type(/dev/ugen0) Jul 28 19:01:54 scone ifdhandler[71277]: ifd_sysdep_device_type: BSD: returning IFD_DEVICE_TYPE_USB Jul 28 19:01:54 scone ifdhandler[71277]: eg_activate: called. Jul 28 19:01:54 scone ifdhandler[71277]: eg_card_status: slot=0 Jul 28 19:01:54 scone ifdhandler[71277]: ifdhandler_poll_presence: card status change: 0 -> 1 Jul 28 19:01:55 scone ifdhandler[71277]: eg_card_status: slot=0 Jul 28 19:02:02 scone last message repeated 7 times Jul 28 19:02:02 scone ifdhandler[71277]: ifdhandler_process: ifdhandler_process(cmd=CT_CMD_RESET, unit=0) Jul 28 19:02:02 scone ifdhandler[71277]: eg_card_reset: called. Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: usb req type=x40 req=x90 val=x0000 ind=x0000 len=0 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: ifd_sysdep_usb_control(0x90) Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL bmRequestType 0x40 bRequest 0x90 wValue 0x0 wIndex 0x0 wLength 0x0 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: ctrl.ucr_data == NULL Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: ifd_sysdep_usb_control(0xa0) Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL bmRequestType 0xc0 bRequest 0xa0 wValue 0x0 wIndex 0x0 wLength 0x1 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL SEND data f0 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL RECV data 00 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: usb req type=xc0 req=xa0 val=x0000 ind=x0000 len=1 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: recv 00 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: ifd_sysdep_usb_control(0x83) Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL bmRequestType 0xc0 bRequest 0x83 wValue 0x0 wIndex 0x0 wLength 0x23 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL SEND data 05 00 00 00 05 00 00 00 00 01 07 28 00 0 0 00 01 64 ca 56 0d 66 84 07 28 00 01 07 28 10 ab bf bf 05 00 00 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL RECV data 3b 95 18 40 ff 62 01 02 01 04 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: usb req type=xc0 req=x83 val=x0000 ind=x0000 len=10 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: recv 3b 95 18 40 ff 62 01 02 01 04 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_protocol_select: atr= 3b 95 18 40 ff 62 01 02 01 04 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_protocol_select: default T=0, supported protocols=0x1 Jul 28 19:02:02 scone ifdhandler[71277]: eg_set_protocol: proto=0 Jul 28 19:02:02 scone ifdhandler[71277]: ifdhandler_process: ifdhandler_process(cmd=CT_CMD_LOCK, unit=0) Jul 28 19:02:02 scone ifdhandler[71277]: ifdhandler_lock: granted excl lock 0 for slot 0 by uid=4294967294 Jul 28 19:02:02 scone ifdhandler[71277]: ifdhandler_process: ifdhandler_process(cmd=CT_CMD_TRANSACT, unit=0) Jul 28 19:02:02 scone ifdhandler[71277]: ifd_protocol_transceive: cmd: c0 a4 00 00 02 3f 00 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: ifd_sysdep_usb_control(0xa0) Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL bmRequestType 0xc0 bRequest 0xa0 wValue 0x0 wIndex 0x0 wLength 0x1 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL SEND data 28 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL RECV data 00 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: usb req type=xc0 req=xa0 val=x0000 ind=x0000 len=1 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: recv 00 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: usb req type=x40 req=x80 val=x0000 ind=x0000 len=5 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_usb_control: send c0 a4 00 00 02 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: ifd_sysdep_usb_control(0x80) Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL bmRequestType 0x40 bRequest 0x80 wValue 0x0 wIndex 0x0 wLength 0x5 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: BSD: CTRL SEND data c0 a4 00 00 02 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_sysdep_usb_control: USB_DO_REQUEST failed: -1 Jul 28 19:02:02 scone ifdhandler[71277]: ifd_protocol_transceive: transceive error: Communication error Jul 28 19:02:02 scone ifdhandler[71277]: ifdhandler_unlock_all: released excl lock 0 for slot 0 by uid=4294967294 Jul 28 19:02:03 scone ifdhandler[71277]: eg_card_status: slot=0 The relevant part of /var/log/messages: Jul 28 19:02:00 scone kernel: usb_event_thread: woke up Jul 28 19:02:00 scone kernel: usb_discover Jul 28 19:02:02 scone kernel: usbd_alloc_xfer() = 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 Jul 28 19:02:02 scone kernel: usbd_dump_queue: pipe=0xc2ee7380 Jul 28 19:02:02 scone kernel: usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 Jul 28 19:02:02 scone kernel: usb_schedsoftintr: polling=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: repeat=0 new head=0 Jul 28 19:02:02 scone kernel: usbd_start_next: pipe=0xc2ee7380, xfer=0 Jul 28 19:02:02 scone kernel: usbd_free_xfer: 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_alloc_xfer() = 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 Jul 28 19:02:02 scone kernel: usbd_dump_queue: pipe=0xc2ee7380 Jul 28 19:02:02 scone kernel: usb_allocmem: use frag=0xc1a81b80 size=1 Jul 28 19:02:02 scone kernel: usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 Jul 28 19:02:02 scone kernel: usb_schedsoftintr: polling=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=1 Jul 28 19:02:02 scone kernel: usb_freemem: frag=0xc1a81b80 Jul 28 19:02:02 scone kernel: usb_transfer_complete: repeat=0 new head=0 Jul 28 19:02:02 scone kernel: usbd_start_next: pipe=0xc2ee7380, xfer=0 Jul 28 19:02:02 scone kernel: usbd_free_xfer: 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_alloc_xfer() = 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 Jul 28 19:02:02 scone kernel: usbd_dump_queue: pipe=0xc2ee7380 Jul 28 19:02:02 scone kernel: usb_allocmem: use frag=0xc1a81b80 size=35 Jul 28 19:02:02 scone kernel: usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 Jul 28 19:02:02 scone kernel: usb_schedsoftintr: polling=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=10 Jul 28 19:02:02 scone kernel: usb_freemem: frag=0xc1a81b80 Jul 28 19:02:02 scone kernel: usb_transfer_complete: repeat=0 new head=0 Jul 28 19:02:02 scone kernel: usbd_start_next: pipe=0xc2ee7380, xfer=0 Jul 28 19:02:02 scone kernel: usbd_free_xfer: 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_alloc_xfer() = 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 Jul 28 19:02:02 scone kernel: usbd_dump_queue: pipe=0xc2ee7380 Jul 28 19:02:02 scone kernel: usb_allocmem: use frag=0xc1a81b80 size=1 Jul 28 19:02:02 scone kernel: usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 Jul 28 19:02:02 scone kernel: usb_schedsoftintr: polling=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=1 Jul 28 19:02:02 scone kernel: usb_freemem: frag=0xc1a81b80 Jul 28 19:02:02 scone kernel: usb_transfer_complete: repeat=0 new head=0 Jul 28 19:02:02 scone kernel: usbd_start_next: pipe=0xc2ee7380, xfer=0 Jul 28 19:02:02 scone kernel: usbd_free_xfer: 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_alloc_xfer() = 0xc43ca200 Jul 28 19:02:02 scone kernel: usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 Jul 28 19:02:02 scone kernel: usbd_dump_queue: pipe=0xc2ee7380 Jul 28 19:02:02 scone kernel: usb_allocmem: use frag=0xc1a81b80 size=5 Jul 28 19:02:02 scone kernel: usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 Jul 28 19:02:02 scone kernel: usb_schedsoftintr: polling=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=17 actlen=5 Jul 28 19:02:02 scone kernel: usb_freemem: frag=0xc1a81b80 Jul 28 19:02:02 scone kernel: usb_transfer_complete: repeat=0 new head=0 Jul 28 19:02:02 scone kernel: usbd_start_next: pipe=0xc2ee7380, xfer=0 Jul 28 19:02:02 scone kernel: usbd_transfer: xfer=0xc43ca200, flags=2, pipe=0xc2ee7380, running=0 Jul 28 19:02:02 scone kernel: usbd_dump_queue: pipe=0xc2ee7380 Jul 28 19:02:02 scone kernel: usb_allocmem: use frag=0xc1a81b80 size=2 Jul 28 19:02:02 scone kernel: usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=5000 Jul 28 19:02:02 scone kernel: usb_schedsoftintr: polling=0 Jul 28 19:02:02 scone kernel: usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=2 Jul 28 19:02:02 scone kernel: usb_freemem: frag=0xc1a81b80 Jul 28 19:02:02 scone kernel: usb_transfer_complete: repeat=0 new head=0 Jul 28 19:02:02 scone kernel: usbd_start_next: pipe=0xc2ee7380, xfer=0 Jul 28 19:02:02 scone kernel: usbd_do_request: status = 0x0000 Jul 28 19:02:02 scone kernel: usbd_free_xfer: 0xc43ca200 Jul 28 19:02:02 scone ifdhandler[71277]: usb_do_request failed: Input/output error (5) The output of dmesg: ums0: at uhub0 port 1 (addr 2) disconnected ums0: detached Jul 28 18:59:27 scone moused: unable to open /dev/ums0: No such file or directory ugen0: at uhub1 port 1 (addr 2) disconnected All threads purged from ugen0 ugen0: detached ugen0: SchlumbergerSema SchlumbergerSema Cryptoflex e-gate, rev 1.10/1.00, addr 2 usb_event_thread: woke up usb_discover usbd_alloc_xfer() = 0xc43ca200 usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 usbd_dump_queue: pipe=0xc2ee7380 usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 usb_schedsoftintr: polling=0 usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=0 usb_transfer_complete: repeat=0 new head=0 usbd_start_next: pipe=0xc2ee7380, xfer=0 usbd_free_xfer: 0xc43ca200 usbd_alloc_xfer() = 0xc43ca200 usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 usbd_dump_queue: pipe=0xc2ee7380 usb_allocmem: use frag=0xc1a81b80 size=1 usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 usb_schedsoftintr: polling=0 usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=1 usb_freemem: frag=0xc1a81b80 usb_transfer_complete: repeat=0 new head=0 usbd_start_next: pipe=0xc2ee7380, xfer=0 usbd_free_xfer: 0xc43ca200 usbd_alloc_xfer() = 0xc43ca200 usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 usbd_dump_queue: pipe=0xc2ee7380 usb_allocmem: use frag=0xc1a81b80 size=35 usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 usb_schedsoftintr: polling=0 usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=10 usb_freemem: frag=0xc1a81b80 usb_transfer_complete: repeat=0 new head=0 usbd_start_next: pipe=0xc2ee7380, xfer=0 usbd_free_xfer: 0xc43ca200 usbd_alloc_xfer() = 0xc43ca200 usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 usbd_dump_queue: pipe=0xc2ee7380 usb_allocmem: use frag=0xc1a81b80 size=1 usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 usb_schedsoftintr: polling=0 usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=1 usb_freemem: frag=0xc1a81b80 usb_transfer_complete: repeat=0 new head=0 usbd_start_next: pipe=0xc2ee7380, xfer=0 usbd_free_xfer: 0xc43ca200 usbd_alloc_xfer() = 0xc43ca200 usbd_transfer: xfer=0xc43ca200, flags=6, pipe=0xc2ee7380, running=0 usbd_dump_queue: pipe=0xc2ee7380 usb_allocmem: use frag=0xc1a81b80 size=5 usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=10000 usb_schedsoftintr: polling=0 usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=17 actlen=5 usb_freemem: frag=0xc1a81b80 usb_transfer_complete: repeat=0 new head=0 usbd_start_next: pipe=0xc2ee7380, xfer=0 usbd_transfer: xfer=0xc43ca200, flags=2, pipe=0xc2ee7380, running=0 usbd_dump_queue: pipe=0xc2ee7380 usb_allocmem: use frag=0xc1a81b80 size=2 usb_insert_transfer: pipe=0xc2ee7380 running=0 timeout=5000 usb_schedsoftintr: polling=0 usb_transfer_complete: pipe=0xc2ee7380 xfer=0xc43ca200 status=0 actlen=2 usb_freemem: frag=0xc1a81b80 usb_transfer_complete: repeat=0 new head=0 usbd_start_next: pipe=0xc2ee7380, xfer=0 usbd_do_request: status = 0x0000 usbd_free_xfer: 0xc43ca200 Any further debugging output needed?