Fix disconnect

[sebastianarena]

Implement a new backoff timeout for SCardGetStatusChange to allow to read proper status changes from the reader. This solves problems detecting a disconnect. It's set to increment wait times from 10ms to 100ms until it stops in an INFINITE wait again.

[LudovicRousseau]

I am not sure what you are trying to solve here. You can/should use SCardCancel() to stop a running SCardGetStatusChange() call.

[santigimeno]

@LudovicRousseau It seems to me it's trying to solve a problem where SCardGetStatusChange returns SCARD_E_TIMEOUT in the initial or initial tries and then it returns SCARD_S_SUCCESS. If this is possible, the library as it is now, when a timeout is received, it stops watching for status change. This can be a problem

[sebastianarena]

Hello @LudovicRousseau @santigimeno. Sorry for not explaining myself better. The solution by @LudovicRousseau is not something I want to solve. I don't want to close the connection myself, but be notified when the reader does that by itself (when the USB is unplugged for example).

I'll start by explaining how this problem can be reproduced. I'm using a ACR12152U-A1 reader. If you use the example provided for the library you can see there's a way to notify then when reader "ends" with the "end" emission of a signal. My problem is that this signal is not reliable, it doesn't return properly on USB disconnections. It's very simple to test. After several tries of the example you should see the SCardGetStatusChange() not properly returning a status change, thus not properly exiting the while(keepWatching) loop.

What I did to solve it was not assume I want to wait FOREVER for every SCardGetStatusChange(). My reader would change very fast several times before disconnecting (an getting to a state 6 which I believe is the combination of SCARD_STATE_CHANGED and SCARD_STATE_UNKNOWN) and the SCardGetStatusChange() would not report this changes correctly every time.

By adding a backoff timeout I was able to get all the changes, and eventually getting out of the loop. In either case the fix I provided can be made into something different as long as FOREVER is not the only option. I implemented a backoff solution to allow waiting a couple of times from 10ms to 100ms and eventually waiting FOREVER.

Hope the explanation is better this time!

[sebastianarena]

Some more info. I went to check the header files to see what was going on on pcsclite.h. There's this for example: #define SCARD_S_SUCCESS ((LONG)0x00000000) Already casted as LONG.

Upon further checking theres a include for wintypes.h which internally do this: typedef long LONG;

Which could lead to the 4bytes / 8bytes problem that I mention.

Maybe. You are the expert here.

[santigimeno]

Ok, I've been able to reproduce the issue in a OS X machine. If I execute the example in the source code with a card reader inserted, it detects the reader. If I disconnect the reader from the machine, a SCARD_STATE_CHANGED | SCARD_STATE_UNKNOWN is reported. If I connect the reader again, it detects the disconnection of the "previous" reader and then the connection of the new reader. Any ideas? I'll look into this more thoroughly in the next few days.

[sebastianarena]

@santigimeno yes, that's what I meant. But that was just one of the cases. What you've reproduced is not consistent. You may actually get both SCARD_STATE_CHANGED | SCARD_STATE_UNKNOWN or you may not get any. If you try my fix, specifically if you try removing the FOREVER timeout and changing to some other value, you always get SCARD_STATE_CHANGED | SCARD_STATE_UNKNOWN.

[santigimeno]

@kaminoo while investigating the issue I've found a bug the thread locking logic that might be related. Can you please try with this: https://github.com/santigimeno/node-pcsclite/tree/fix_locks? Thanks

[santigimeno]

I think there was another error in the logic that calculated the exit condition in the HandlerFunction loop. It was checking dwCurrentState instead of dwEventState. Updated the fix_locks branch. It works for me in OS X. Could you test if it works for you? Thanks!

[sebastianarena]

@santigimeno the proposed fix was also part of my commit. It was the first thing I noticed. I think it's part of it, but I still have the issue. My ACR1252U connects but upon unplug I get random disconnects. It will always send the disconnect when re-connecting. This is a step towards the fix. Check the timeout like I suggested, and you'll find it will always work. Thanks for taking the time to fix this Seba

[santigimeno]

@kaminoo you're right. I hadn't noticed that in your commit and definitely it was a bug. The problem I'm having now is that I can't reproduce the issue anymore. Could you please run the example.js with the code in my branch and paste the output marking when you plug / unplug the reader?

[sebastianarena]

@santigimeno Here it goes. This is from a single run. As you can see... the first time the disconnect notification works, but not the second time. This behavior is erratic and can sometimes report nothing at all.

PLUG IN New reader detected ACS ACR1252 1S CL Reader(1) Status( ACS ACR1252 1S CL Reader(1) ): { state: 18, atr: <Buffer > } card removed Disconnected Status( ACS ACR1252 1S CL Reader(1) ): { state: 16, atr: <Buffer > } New reader detected ACS ACR1252 1S CL Reader(2) Status( ACS ACR1252 1S CL Reader(2) ): { state: 546, atr: <Buffer > } card inserted [Error: SCardConnect error: No smart card inserted.(0x8010000c)]

PLUG OFF Reader ACS ACR1252 1S CL Reader(1) removed Reader ACS ACR1252 1S CL Reader(2) removed

PLUG IN New reader detected ACS ACR1252 1S CL Reader(1) Status( ACS ACR1252 1S CL Reader(1) ): { state: 18, atr: <Buffer > } card removed Disconnected Status( ACS ACR1252 1S CL Reader(1) ): { state: 16, atr: <Buffer > } New reader detected ACS ACR1252 1S CL Reader(2) Status( ACS ACR1252 1S CL Reader(2) ): { state: 546, atr: <Buffer > } card inserted [Error: SCardConnect error: No smart card inserted.(0x8010000c)]

PLUG OFF Reader ACS ACR1252 1S CL Reader(1) removed Status( ACS ACR1252 1S CL Reader(2) ): { state: 544, atr: <Buffer > }

PLUG IN Reader ACS ACR1252 1S CL Reader(2) removed New reader detected ACS ACR1252 1S CL Reader(1) Status( ACS ACR1252 1S CL Reader(1) ): { state: 18, atr: <Buffer > } card removed Disconnected Status( ACS ACR1252 1S CL Reader(1) ): { state: 16, atr: <Buffer > } New reader detected ACS ACR1252 1S CL Reader(2) Status( ACS ACR1252 1S CL Reader(2) ): { state: 546, atr: <Buffer > } card inserted [Error: SCardConnect error: No smart card inserted.(0x8010000c)]

[santigimeno]

@kaminoo I see... Does the same happen if both readers don't have any card inserted?

[santigimeno]

BTW what node / iojs version are you using?

[santigimeno]

It's weird. From the output you pasted, it detects that a card is inserted in the reader 2 but when trying to connect it returns a No smart card inserted error

[sebastianarena]

@santigimeno some more data:

1) The reader I have presents itself as two readers, I'm just plugging in one usb 2) For the tests I never put a card in, I just wanted to insert / remove the usb 3) I'm using NodeJS 4.1.0, also happened in NodeJS 4.0.0

[sebastianarena]

@santigimeno any new ideas on this? Were you able to reproduce this problem?

[santigimeno]

@kaminoo yes, my idea is testing in a OS X with one of those devices with 2 readers. I can get one in a couple of days but I don't know when I'll be able to test it as I'm quite busy at the moment. As soon as I have some results I'll let you know

[santigimeno]

@kaminoo I have updated the fix_locks branch. Can you test again?

[sebastianarena]

The branch stopped compiling :( Here's the problems that the node-gyp rebuild reports:

npm WARN package.json pcsclite@0.4.2 license should be a valid SPDX license expression |

buffertools@2.1.3 install /Developer/Tools/node-pcsclite.orig/node_modules/buffertools node-gyp rebuild

CXX(target) Release/obj.target/buffertools/buffertools.o SOLINK_MODULE(target) Release/buffertools.node /

pcsclite@0.4.2 install /Developer/Tools/node-pcsclite.orig node-gyp rebuild

CXX(target) Release/obj.target/pcsclite/src/addon.o In file included from ../src/addon.cpp:1: In file included from ../src/pcsclite.h:6: /usr/local/include/PCSC/winscard.h:43:10: error: 'pcsclite.h' file not found with include; use "quotes" instead

include

     ^

In file included from ../src/addon.cpp:1: In file included from ../src/pcsclite.h:6: In file included from /usr/local/include/PCSC/winscard.h:43: /usr/local/include/PCSC/pcsclite.h:47:10: error: 'wintypes.h' file not found with include; use "quotes" instead

include

     ^

2 errors generated. make: *\ [Release/obj.target/pcsclite/src/addon.o] Error 1 gyp ERR! build error gyp ERR! stack Error: make failed with exit code: 2 gyp ERR! stack at ChildProcess.onExit (/usr/local/lib/node_modules/npm/node_modules/node-gyp/lib/build.js:270:23) gyp ERR! stack at emitTwo (events.js:87:13) gyp ERR! stack at ChildProcess.emit (events.js:172:7) gyp ERR! stack at Process.ChildProcess._handle.onexit (internal/child_process.js:200:12) gyp ERR! System Darwin 14.5.0 gyp ERR! command "/usr/local/bin/node" "/usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild" gyp ERR! cwd /Developer/Tools/node-pcsclite.orig gyp ERR! node -v v4.1.0 gyp ERR! node-gyp -v v3.0.3 gyp ERR! not ok

npm ERR! Darwin 14.5.0 npm ERR! argv "/usr/local/bin/node" "/usr/local/bin/npm" "install" npm ERR! node v4.1.0 npm ERR! npm v2.14.3 npm ERR! code ELIFECYCLE npm ERR! pcsclite@0.4.2 install: node-gyp rebuild npm ERR! Exit status 1 npm ERR! npm ERR! Failed at the pcsclite@0.4.2 install script 'node-gyp rebuild'. npm ERR! This is most likely a problem with the pcsclite package, npm ERR! not with npm itself. npm ERR! Tell the author that this fails on your system: npm ERR! node-gyp rebuild npm ERR! You can get their info via: npm ERR! npm owner ls pcsclite npm ERR! There is likely additional logging output above.

npm ERR! Please include the following file with any support request: npm ERR! /Developer/Tools/node-pcsclite.orig/npm-debug.log

[santigimeno]

@kaminoo Nothing in the code changed to make it fail. In fact, I had the same problem. Won't you have pcsc-lite from brew installed? I had, and removing it solved my problem

[sebastianarena]

@santigimeno super weird. I do have it installed via brew. I removed it, but same problem :( will take a look, don't know what is going on.

[santigimeno]

@kaminoo I think the last Xcode upgrade has messed up things. Delete all modules and install it again:

$ rm -r node_modules
$ npm install

[sebastianarena]

@santigimeno Yes! that's what I figured it had changed... I installed the xcode console tools for developing in the last days (I had Xcode before, but not the latest version)... and probably changed stuff. Removing the node_modules doesn't change anything :(((

[santigimeno]

@kaminoo that does not make sense, pcsclite.h is not installed in that path: /usr/local/include/PCSC/pcsclite.h. brew version does install it there. Have you deleted the build folder? How have you run node-gyp rebuild only? Have you run node-gyp configure before?

[sebastianarena]

@santigimeno I have the file /usr/local/include/PCSC/pcsclite.h there. Shouldn't it be? node-gyp configure works ok node-gyp rebuild fails with the errors I showed you

Might this be it?? GCC is actually LLVM

gcc --version Configured with: --prefix=/Applications/Xcode.app/Contents/Developer/usr --with-gxx-include-dir=/usr/include/c++/4.2.1 Apple LLVM version 7.0.0 (clang-700.0.72) Target: x86_64-apple-darwin14.5.0 Thread model: posix

[sebastianarena]

@santigimeno sorry man, this gets complicated with each iteration :(

[santigimeno]

@kaminoo I have it here: /System/Library/Frameworks/PCSC.framework/Versions/A/Headers/wintypes.h /System/Library/Frameworks/PCSC.framework/Versions/A/Headers/pcsclite.h

[sebastianarena]

@santigimeno removed the version that I had in /usr/local/ which I don't know here it came from. It compiled perfectly with the system libraries. Will test the fix in the next hours. I don't have the reader with me right now... thanks for the help again!

[sebastianarena]

@santigimeno the fix works! tried it at least ten times, pluggin in/out and detection was always good. Awesome.

[santigimeno]

That's great news! I'll merge the code when I have time. Thanks!!

[santigimeno]

Fixed in 0.4.4. Commits: https://github.com/santigimeno/node-pcsclite/commit/8f3309520d9fac4c8da36002b9b80c43212a5159 https://github.com/santigimeno/node-pcsclite/commit/0a3eaafb2bc6b543134d8959928e6fbf47d91a2c