Attachment 644093 Details for Bug 875892 – client_logs_sc20121113.log

client_logs_sc20121113.log

client_logs_sc20121113.log (text/plain), 15.21 KB, created by Marian Krcmarik on 2012-11-13 13:14:17 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Marian Krcmarik

Created: 2012-11-13 13:14:17 UTC

Size: 15.21 KB

patch

obsolete

>remote-viewer debug on the client when sc inserted:
>(remote-viewer:16593): GSpice-DEBUG: smartcard-manager.c:298 smartcard: card-removed
>(remote-viewer:16593): GSpice-DEBUG: channel-smartcard.c:331 smartcard-8:0: send message 6, queued
>(remote-viewer:16593): GSpice-DEBUG: channel-smartcard.c:504 smartcard-8:0: handle msg 2
>(remote-viewer:16593): GSpice-DEBUG: channel-smartcard.c:508 smartcard-8:0: in flight 6
>=======================================================================================================
>QEMU stdout:
>/usr/libexec/qemu-kvm -m 1024 -smp 1 -vga qxl -enable-kvm -spice port=3002,disable-ticketing,seamless-migration=off -device virtio-serial-pci,id=virtio-serial0,bus=pci.0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -device AC97  -chardev spicevmc,server,name=smartcard,debug=10,id=ccid -device usb-ccid -device ccid-card-passthru,debug=10,chardev=ccid -usb /dev/rootvg/RHEL6.1_test -global qxl-vga.revision=4 -monitor stdio
>ccid-card-passthru: initing chardev
>scd:   1: spice_chr_write: 12
>scd:   1: vmc_register_interface
>scd:   1: vmc_read: (nil) 282/0/0
>scd:   2: vmc_read: 0x7fff33a6d8b0 282/12/12
>scd:   3: vmc_read: 0x7fff33a6d8bc 270/0/0
>scd:   2: spice_chr_write: 12
>scd:   4: vmc_read: 0x7fff33a6d8e0 270/12/12
>scd:   5: vmc_read: 0x7fff33a6d8ec 282/0/0
>scd:   6: vmc_read: 0x7fff33a6d8ec 282/0/0
>QEMU 0.12.1 monitor - type 'help' for more information
>(qemu) main_channel_link: add main channel client
>main_channel_handle_parsed: net test: latency 0.173000 ms, bitrate 10343434343 bps (9864.267676 Mbps)
>inputs_connect: inputs channel client create
>scd:   7: vmc_read: 0x7fff33a6d8ec 282/0/0
>red_dispatcher_set_cursor_peer: 
>scd:   3: spice_chr_write: 12
>scd:   8: vmc_read: 0x7fff33a6d5e0 282/12/12
>scd:   9: vmc_read: 0x7fff33a6d5ec 270/0/0
>scd:   4: spice_chr_write: 4
>scd:  10: vmc_read: 0x7fff33a6d610 270/4/4
>scd:  11: vmc_read: 0x7fff33a6d614 282/0/0
>scd:   1: vmc_write: 12/12
>main_channel_handle_parsed: agent start
>main_channel_handle_parsed: agent start
>ccid-card-passthru: VSC_CardRemove
>scd:   5: spice_chr_write: 12
>scd:  12: vmc_read: 0x7fff33a6d5e0 282/12/12
>scd:  13: vmc_read: 0x7fff33a6d5ec 270/0/0
>scd:   6: spice_chr_write: 4
>scd:  14: vmc_read: 0x7fff33a6d610 270/4/4
>scd:  15: vmc_read: 0x7fff33a6d614 282/0/0
>scd:   2: vmc_write: 12/12
>
>=================================================================================================================
>sudo pcscd --foreground --debug on the client:
>00000000 pcscdaemon.c:267:main() pcscd set to foreground with debug send to stderr
>00000027 debuglog.c:239:DebugLogSetLevel() debug level=debug
>00000687 pcscdaemon.c:506:main() pcsc-lite 1.5.2 daemon ready.
>00094939 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x08E6, PID: 0x3437
>00000017 hotplug_libhal.c:342:HPAddDevice() Adding USB device: usb_device_8e6_3437_noserial_if0
>01000534 readerfactory.c:1024:RFInitializeReader() Attempting startup of Gemplus GemPC Twin 00 00 using /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
>00023607 readerfactory.c:877:RFBindFunctions() Loading IFD Handler 3.0
>00000034 ifdhandler.c:1377:init_driver() Driver version: 1.3.9
>00000190 ifdhandler.c:1390:init_driver() LogLevel: 0x0003
>00000135 ifdhandler.c:1410:init_driver() DriverOptions: 0x0000
>00000006 ifdhandler.c:81:IFDHCreateChannelByName() lun: 0, device: usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0
>00096686 ccid_usb.c:236:OpenUSBByName() Manufacturer: Ludovic Rousseau (ludovic.rousseau@free.fr)
>00000145 ccid_usb.c:246:OpenUSBByName() ProductString: Generic CCID driver
>00000130 ccid_usb.c:252:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
>00000748 ccid_usb.c:408:OpenUSBByName() Found Vendor/Product: 08E6/3437 (Gemplus GemPC Twin)
>00000004 ccid_usb.c:410:OpenUSBByName() Using USB bus/device: 001/017
>00002804 ccid_usb.c:816:get_data_rates() declared: 10753 bps
>00000007 ccid_usb.c:816:get_data_rates() declared: 14337 bps
>00000004 ccid_usb.c:816:get_data_rates() declared: 15625 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 17204 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 20833 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 21505 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 23438 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 25806 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 28674 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 31250 bps
>00000006 ccid_usb.c:816:get_data_rates() declared: 32258 bps
>00000005 ccid_usb.c:816:get_data_rates() declared: 34409 bps
>00000004 ccid_usb.c:816:get_data_rates() declared: 39063 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 41667 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 43011 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 46875 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 52083 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 53763 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 57348 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 62500 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 64516 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 68817 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 71685 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 78125 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 83333 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 86022 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 93750 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 104167 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 107527 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 114695 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 125000 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 129032 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 143369 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 156250 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 166667 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 172043 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 215054 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 229391 bps
>00000002 ccid_usb.c:816:get_data_rates() declared: 250000 bps
>00000003 ccid_usb.c:816:get_data_rates() declared: 344086 bps
>00000516 ifdhandler.c:334:IFDHGetCapabilities() tag: 0xFB0, usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00000006 readerfactory.c:249:RFAddReader() Using the pcscd polling thread
>00000515 ifdhandler.c:334:IFDHGetCapabilities() tag: 0xFAE, usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00000007 ifdhandler.c:377:IFDHGetCapabilities() Reader supports 1 slot(s)
>00001348 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x04B3, PID: 0x3025
>00001120 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x046D, PID: 0xC069
>00000820 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x17EF, PID: 0x100A
>00027626 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x8087, PID: 0x0020
>00001129 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x1D6B, PID: 0x0002
>00003994 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x8087, PID: 0x0020
>00001290 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x17EF, PID: 0x480F
>00001502 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x17EF, PID: 0x480F
>00001069 hotplug_libhal.c:307:get_driver() Looking a driver for VID: 0x1D6B, PID: 0x0002
>00001855 winscard_msg_srv.c:239:SHMProcessEventsServer() Common channel packet arrival
>00000025 winscard_msg_srv.c:248:SHMProcessEventsServer() SHMProcessCommonChannelRequest detects: 7
>00000006 pcscdaemon.c:147:SVCServiceRunLoop() A new context thread creation is requested: 7
>00000314 winscard_svc.c:133:ContextThread() Thread is started: 7
>00000033 winscard_msg_srv.c:317:SHMProcessEventsContext() command CMD_VERSION received by client 7
>00000005 winscard_svc.c:189:ContextThread() Client is protocol version 3:0
>00000044 winscard_msg_srv.c:317:SHMProcessEventsContext() command ESTABLISH_CONTEXT received by client 7
>00000015 winscard.c:242:SCardEstablishContext() Establishing Context: 16985328
>00000232 winscard_msg_srv.c:317:SHMProcessEventsContext() command CONNECT received by client 7
>00000011 winscard.c:303:SCardConnect() Attempting Connect to Gemplus GemPC Twin 00 00 using protocol: 3
>00000006 winscard.c:362:SCardConnect() Card Not Inserted
>00023909 utils.c:115:StatSynchronize() status file: /var/run/pcscd.events/event.16593.16985328
>10937541 winscard_msg_srv.c:239:SHMProcessEventsServer() Common channel packet arrival
>00000019 winscard_msg_srv.c:248:SHMProcessEventsServer() SHMProcessCommonChannelRequest detects: 8
>00000005 pcscdaemon.c:147:SVCServiceRunLoop() A new context thread creation is requested: 8
>00000097 winscard_svc.c:133:ContextThread() Thread is started: 8
>00000040 winscard_msg_srv.c:317:SHMProcessEventsContext() command CMD_VERSION received by client 8
>00000011 winscard_svc.c:189:ContextThread() Client is protocol version 3:0
>00000094 winscard_msg_srv.c:317:SHMProcessEventsContext() command ESTABLISH_CONTEXT received by client 8
>00000028 winscard.c:242:SCardEstablishContext() Establishing Context: 16984186
>15098028 ifdhandler.c:964:IFDHPowerICC() action: PowerUp, usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00772164 utils.c:115:StatSynchronize() status file: /var/run/pcscd.events/event.16630.16984186
>00000114 utils.c:115:StatSynchronize() status file: /var/run/pcscd.events/event.16593.16985328
>00000068 eventhandler.c:429:EHStatusHandlerThread() Card inserted into Gemplus GemPC Twin 00 00
>00000020 Card ATR: 3B 95 95 40 FF AE 01 03 00 00 
>00000202 winscard_msg_srv.c:317:SHMProcessEventsContext() command CONNECT received by client 7
>00000016 winscard.c:303:SCardConnect() Attempting Connect to Gemplus GemPC Twin 00 00 using protocol: 3
>00000012 prothandler.c:128:PHSetProtocol() Attempting PTS to T=0
>00000014 ifdhandler.c:522:IFDHSetProtocolParameters() protocol T=0, usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00014076 winscard.c:449:SCardConnect() Active Protocol: T=0
>00000082 winscard.c:459:SCardConnect() hCard Identity: 15df6
>00265492 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000161 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000137 winscard_msg_srv.c:317:SHMProcessEventsContext() command BEGIN_TRANSACTION received by client 7
>00000020 winscard.c:1057:SCardBeginTransaction() Status: 0x00000000
>00101024 winscard_msg_srv.c:317:SHMProcessEventsContext() command TRANSMIT received by client 7
>00000037 winscard.c:1647:SCardTransmit() Send Protocol: T=0
>00000077 ifdhandler.c:1091:IFDHTransmitToICC() usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00018270 winscard_msg_srv.c:317:SHMProcessEventsContext() command TRANSMIT received by client 7
>00000023 winscard.c:1647:SCardTransmit() Send Protocol: T=0
>00000010 ifdhandler.c:1091:IFDHTransmitToICC() usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00017267 winscard_msg_srv.c:317:SHMProcessEventsContext() command TRANSMIT received by client 7
>00000024 winscard.c:1647:SCardTransmit() Send Protocol: T=0
>00000267 ifdhandler.c:1091:IFDHTransmitToICC() usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00062965 winscard_msg_srv.c:317:SHMProcessEventsContext() command END_TRANSACTION received by client 7
>00000024 winscard.c:1208:SCardEndTransaction() Status: 0x00000000
>00005997 utils.c:115:StatSynchronize() status file: /var/run/pcscd.events/event.16630.16984186
>00004169 winscard_msg_srv.c:317:SHMProcessEventsContext() command BEGIN_TRANSACTION received by client 7
>00000019 winscard.c:1057:SCardBeginTransaction() Status: 0x00000000
>00039403 winscard_msg_srv.c:317:SHMProcessEventsContext() command TRANSMIT received by client 7
>00000024 winscard.c:1647:SCardTransmit() Send Protocol: T=0
>00000012 ifdhandler.c:1091:IFDHTransmitToICC() usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00007958 winscard_msg_srv.c:317:SHMProcessEventsContext() command TRANSMIT received by client 7
>00000016 winscard.c:1647:SCardTransmit() Send Protocol: T=0
>00000008 ifdhandler.c:1091:IFDHTransmitToICC() usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00005842 winscard_msg_srv.c:317:SHMProcessEventsContext() command TRANSMIT received by client 7
>00000020 winscard.c:1647:SCardTransmit() Send Protocol: T=0
>00000013 ifdhandler.c:1091:IFDHTransmitToICC() usb:08e6/3437:libhal:/org/freedesktop/Hal/devices/usb_device_8e6_3437_noserial_if0 (lun: 0)
>00011144 winscard_msg_srv.c:317:SHMProcessEventsContext() command END_TRANSACTION received by client 7
>00000021 winscard.c:1208:SCardEndTransaction() Status: 0x00000000
>00009102 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000140 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000200 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000134 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000289 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000106 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000132 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000103 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000207 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000130 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000168 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>00000108 winscard_msg_srv.c:317:SHMProcessEventsContext() command STATUS received by client 7
>
>=============================================================================================================
>pcsc_scan on the client when sc is inserted:
>$ pcsc_scan 
>PC/SC device scanner
>V 1.4.17 (c) 2001-2009, Ludovic Rousseau <ludovic.rousseau@free.fr>
>Compiled with PC/SC lite version: 1.6.4
>Scanning present readers...
>0: Gemplus GemPC Twin 00 00
>
>Tue Nov 13 13:43:42 2012
> Reader 0: Gemplus GemPC Twin 00 00
>  Card state: Card removed, 
>
>Tue Nov 13 13:43:58 2012
> Reader 0: Gemplus GemPC Twin 00 00
>  Card state: Card inserted, 
>  ATR: 3B 95 95 40 FF AE 01 03 00 00
>
>ATR: 3B 95 95 40 FF AE 01 03 00 00
>+ TS = 3B --> Direct Convention
>+ T0 = 95, Y(1): 1001, K: 5 (historical bytes)
>  TA(1) = 95 --> Fi=512, Di=16, 32 cycles/ETU
>    125000 bits/s at 4 MHz, fMax for Fi = 5 MHz => 156250 bits/s
>  TD(1) = 40 --> Y(i+1) = 0100, Protocol T = 0 
>-----
>  TC(2) = FF --> Work waiting time: 960 x 255 x (Fi/F)
>+ Historical bytes: AE 01 03 00 00
>  Category indicator byte: AE (proprietary format)
>
>Possibly identified card (using /usr/share/pcsc/smartcard_list.txt):
>3B 95 95 40 FF AE 01 03 00 00
>	Axalto - Cyberflex 64K
>	Gemalto TOP IM FIPS CY2 (product code HWP115291A)
>
>

Actions: View

Attachments on bug 875892: 643663 | 644092 | 644093