OpenSC MacOS: Parallel codesigning (a la Xcode) results in "errSecInternalComponent"

Problem Description

Goal: I am trying to sign an iOS app with a certificate on my Yubikey.

Problem: After successfully building my iOS app through Xcode, Xcode tries to sign the app using codesign. This results in indeterminate failures with code errSecInternalComponent. After some inspection, it seems that the cause of this is codesign being called in parallel processes (recreated below).

Proposed Resolution

Lock access to codesigning from a single process.

Steps to reproduce

I have the following two scripts that simply codesign all arbitrary text files in a directory. One signs serially while the other one opens a new process for each code signature.

#!/bin/bash
# serial_codesign_test.sh

# Get the codesigning identity
if [ -z "$1" ]
    then
        echo "Please specify the codesigning identity with the first parameter."
        exit 1;
fi
IDENTITY="$1"

for f in *.txt
do
    # Codesign Serially
    codesign -fs "$IDENTITY" "$f"
done

exit 0;

#!/bin/bash
# parallel_codesign_test.sh

# Get the codesigning identity
if [ -z "$1" ]
    then
        echo "Please specify the codesigning identity with the first parameter."
        exit 1;
fi
IDENTITY="$1"

for f in *.txt
do
    # Codesign in Parallel
    codesign -fs "$IDENTITY" "$f" &
done

exit 0;

The error is easily reproducible with the following:

./parallel_codesign_test.sh $IDENTITY_ON_YUBIKEY

Logs

➜  codesign_files ./serial_codesign_test.sh $IDENTITY_IN_LOCAL_KEYCHAIN
test_0.txt: replacing existing signature
test_1.txt: replacing existing signature
test_2.txt: replacing existing signature
test_3.txt: replacing existing signature
test_4.txt: replacing existing signature
test_5.txt: replacing existing signature
test_6.txt: replacing existing signature
test_7.txt: replacing existing signature
test_8.txt: replacing existing signature
test_9.txt: replacing existing signature

➜  codesign_files ./serial_codesign_test.sh $IDENTITY_ON_YUBIKEY
test_0.txt: replacing existing signature
test_1.txt: replacing existing signature
test_2.txt: replacing existing signature
test_3.txt: replacing existing signature
test_4.txt: replacing existing signature
test_5.txt: replacing existing signature
test_6.txt: replacing existing signature
test_7.txt: replacing existing signature
test_8.txt: replacing existing signature
test_9.txt: replacing existing signature

➜  codesign_files ./parallel_codesign_test.sh $IDENTITY_IN_LOCAL_KEYCHAIN
➜  codesign_files test_4.txt: replacing existing signature
test_8.txt: replacing existing signature
test_5.txt: replacing existing signature
test_1.txt: replacing existing signature
test_9.txt: replacing existing signature
test_0.txt: replacing existing signature
test_6.txt: replacing existing signature
test_3.txt: replacing existing signature
test_7.txt: replacing existing signature
test_2.txt: replacing existing signature

➜  codesign_files ./parallel_codesign_test.sh $IDENTITY_ON_YUBIKEY
➜  codesign_files test_0.txt: replacing existing signature
test_1.txt: replacing existing signature
test_7.txt: replacing existing signature
test_1.txt: errSecInternalComponent
test_5.txt: replacing existing signature
test_7.txt: errSecInternalComponent
test_2.txt: replacing existing signature
test_5.txt: errSecInternalComponent
test_8.txt: replacing existing signature
test_2.txt: errSecInternalComponent
test_6.txt: replacing existing signature
test_8.txt: errSecInternalComponent
test_6.txt: errSecInternalComponent
test_9.txt: replacing existing signature
test_9.txt: errSecInternalComponent
test_4.txt: replacing existing signature
test_3.txt: replacing existing signature
test_3.txt: errSecInternalComponent

Mar 14 '20 18:03 herm-cb

OpenSC debug=3 logs here

Mar 15 '20 04:03 herm-cb

Quick look at the log show the card has lost the login state and pin caching is off. Try turning on pin caching in opensc.conf. Login state can be lost by commands set to the device during card matching by other OpenSC drivers. Try running with env OPENSC_DRIVER=PIV-II or modify opensc.conf to ser drivers = to the only cards you expect to use.

I do not have any MacOS systems and never looked at reader-cryptotokenkit.m to see if pcsc does better locking then cryptotokenkit.

https://smartcard-atr.apdu.fr/parse?ATR=3B+FD+13+00+00+81+31+FE+15+80+73+C0+21+C0+57+59+75+62+69+4B+65+79+40 says you have a "Yubico YubiKey 5 NFC (PKI)" The card-piv.c does not recognize this as a Yubikey so calls it a generic PIV card, type = 14001. Yubikey devices can lose the login state because they do not strictly follow the NIST PIV standards. card-piv.c tries to address many of these issues if it can identify the card. I do not have any Yubico 5 devices.

If you are willing to run some tests using your device, I will send you a script later in the week.

Mar 15 '20 12:03 dengert

Correction should be OPENSC_DRIVER=PIV-II

Mar 15 '20 12:03 dengert

@dengert Thanks for the feedback!

I only had pin caching turned off to see if that would help, but it does not. I re-enabled it, and it doesn't have any change.

Setting OPENSC_DRIVER=PIV-II didn't have any effect. How would I explicitly set this in opensc.conf?

I would gladly run some test scripts! I did notice that my yubikey model doesn't seem explicitly supported.

For what it's worth, this does't look like a new issue. I found this from 2018:

https://forums.developer.apple.com/thread/106938

Mar 15 '20 15:03 herm-cb

To only use selected drivers via opensc.conf see: https://github.com/OpenSC/OpenSC/blob/master/etc/opensc.conf.example.in#L136

To simulate a Yubkey4 you can also add to opensc.conf:

# make Yubico 5 look like Yubico 4 for testing
   card_atr  3B:FD:13:00:00:81:31:FE:15:80:73:C0:21:C0:57:59:75:62:69:4B:65:79:40 {
                driver = "PIV-II";
                type = 14004;
   }

Mar 15 '20 18:03 dengert

@dengert Got it, thanks! This still didn't have any net effect, but cool to know I can do this. What exactly is type = 14004 doing here?

Mar 15 '20 22:03 herm-cb

Its the card number for a Yubikey 4 with PIV applet https://github.com/OpenSC/OpenSC/blob/master/src/libopensc/cards.h#L137

Mar 15 '20 22:03 dengert

@dengert Thanks that's helpful! The bug is still there though.

Mar 17 '20 00:03 herm-cb

In the previous log, it was for just one process and the process had multiple threads.

Your serial_codesign_test.sh all work, and the parallel_codesign_test.sh has many failures. pcsc does the process locking on other systems, and locking within threads and processes work well. This implies that the process locking done by reader-cryptotokenkit.m (between processes ) has a problem. Other possible problems are detection of the lost of login state and its recovery or the pin caching code is not using the locking correctly.

in the parallel run, 8 of the 10 process failed. So it looks like you can get a failure with just 3. OpenSC should write to the log from multiple processes, without losing any lines, as last resort your script could used env OPENSC_CONF= to point to a copy of opensc.conf with a different debug_file = opensc-debug.log; for each process without losing any lines. But then the logs have to be compared by time stamps.

Can you send a log of the failing test using the type=14004 I want to see what is different. This should show better test of lost login state and might show interference between processes.

I do not have a MacOS device so never looked at reader-cryptotokenkit.m. It might be releasing an exclusive lock to early, or is only doing a shared lock of some type.

@frankmorgner you wrote reader-cryptotokenkit.m in 2017, any ideas?

@mouse07410 any ideas? Can you reproduce?

Mar 17 '20 12:03 dengert

https://github.com/frankmorgner/OpenSCToken/blob/master/OpenSCToken/Token.m#L83 looks like thread locking is not enabled. @frankmorgner

This problem is very similar to https://github.com/OpenSC/OpenSC/issues/1966 in that the debug log does not show enough info to tell if thread locking is working or not. sc_mutex_lock and friends return SC_SUCCESS if no thread locking is being done.

Mar 17 '20 14:03 dengert

@dengert it looks like you narrowed the problem down -- would those logs still help?

Mar 17 '20 17:03 herm-cb

You can hold off until Frank has a look.

Mar 17 '20 17:03 dengert

Sigh, It looks like CTK is not clever enough to manage concurrent access within a single process. Yes, we're locking the reader with the designated method beginSessionWithReply, but in your log we can see that, for example, thread 0x123145548386304 is holding a lock for the card when thread 0x123145548922880 is requesting (and getting) a lock as well:

P:3075; T:0x123145548386304 21:31:54.143 [cryptotokenkit] reader-cryptotokenkit.m:211:cryptotokenkit_lock: called
P:3075; T:0x123145548386304 21:31:54.143 [cryptotokenkit] reader-cryptotokenkit.m:233:cryptotokenkit_lock: returning with: 0 (Success)
...
P:3075; T:0x123145548386304 21:31:54.360 [cryptotokenkit] reader-cryptotokenkit.m:240:cryptotokenkit_unlock: called
P:3075; T:0x123145548386304 21:31:54.360 [cryptotokenkit] reader-cryptotokenkit.m:247:cryptotokenkit_unlock: returning with: 0 (Success)

P:3075; T:0x123145548922880 21:31:54.166 [cryptotokenkit] reader-cryptotokenkit.m:211:cryptotokenkit_lock: called
P:3075; T:0x123145548922880 21:31:54.166 [cryptotokenkit] reader-cryptotokenkit.m:233:cryptotokenkit_lock: returning with: 0 (Success)
...
P:3075; T:0x123145548922880 21:31:54.172 [cryptotokenkit] reader-cryptotokenkit.m:240:cryptotokenkit_unlock: called
P:3075; T:0x123145548922880 21:31:54.172 [cryptotokenkit] reader-cryptotokenkit.m:247:cryptotokenkit_unlock: returning with: 0 (Success)

I think that should be solved by using a global lock in cryptotokenkit_lock...

Mar 19 '20 22:03 frankmorgner

I've implemented a fix here https://github.com/OpenSC/OpenSC/pull/1985, but I currently don't have time to create binaries nor test it.

Mar 19 '20 22:03 frankmorgner

@frankmorgner @dengert I would gladly test but I'm pretty newb to this repo. Any quick links on building on mac?

Mar 20 '20 04:03 herm-cb

So after poking around, I ran ./MacOSX/build from the root, and I was able to generate the dmg, but the install fails on "Validating Packages". Am I missing something?

Mar 20 '20 05:03 herm-cb

First, before the build do ./bootstrap

Second, if that fails you can try the fork https://GitHub.com/mouse07410/OpenSC.git - if that builds, I'll add the PR in question.

Mar 20 '20 10:03 mouse07410

@mouse07410 Your branch builds, but it unfortunately is breaking everything for me.

For starters, when I run:

/Library/OpenSC/bin/pkcs11-tool --login --test

I get...

Using slot 0 with a present token (0x0)
Logging in to "iPhone Distribution...".
Please enter User PIN:
C_SeedRandom() and C_GenerateRandom():
  seeding (C_SeedRandom) not supported
  seems to be OK
Digests: not implemented
Signatures (currently only for RSA)
  testing key 0 (KEY MAN key)
  all 4 signature functions seem to work
  testing signature mechanisms:
unable to verify signature (compile with ENABLE_OPENSSL)
unable to verify signature (compile with ENABLE_OPENSSL)
    RSA-X-509:     RSA-PKCS: Verify: not implemented
Decryption (currently only for RSA)
  testing key 0 (KEY MAN key)
No OpenSSL support, unable to validate decryption
No errors

Mar 20 '20 19:03 herm-cb

Sorry, I can not help. Do not have a Mac. But, verify operations are done in software., Test data for decryption test is encrypted in software by using OpenSSL.

Mar 20 '20 19:03 dengert

@mouse07410 I've tried building your fork with openSSL (by adding --enable-openssl in MacOSX/build script), but am getting this error:

configure: error: OpenSSL linkage required, but no OpenSSL was found

@frankmorgner any other ideas on how I can test this? I've burnt a couple days just trying to get this running from source on Mac, and I'm having some real struggles.

Mar 22 '20 04:03 herm-cb

Update: I was able to get the OpenSSL linking figured out with the following:

LDLFLAGS=-L/usr/local/opt/[email protected]/lib
CPPFLAGS=-I/usr/local/opt/[email protected]/include
PKG_CONFIG_PATH=/usr/local/opt/[email protected]/lib/pkgconfig

But I'm now stuck on:

Making all in unittests
gcc -DHAVE_CONFIG_H -I. -I../../..   -I/usr/local/opt/[email protected]/include -I../../../src/ -L../../../src/libopensc/  -I/usr/local/Cellar/cmocka/1.1.5/include -Wall -Wextra -Wno-unused-parameter -Werror -g -O2 -c -o asn1.o asn1.c
clang: error: argument unused during compilation: '-L../../../src/libopensc/' [-Werror,-Wunused-command-line-argument]
make[4]: *** [asn1.o] Error 1
make[3]: *** [all-recursive] Error 1
make[2]: *** [all-recursive] Error 1
make[1]: *** [all-recursive] Error 1
make: *** [all] Error 2

This is on both forks.

Mar 22 '20 14:03 herm-cb

@herm-cb my OpenSSL is Macports-installed, so in a location different from Brew (/opt/local).

But you are building with gcc instead of Xcode-provided clang? Any specific reason for that?

Mar 27 '20 19:03 mouse07410

@herm-cb sorry for the late response. the days are busy...

This description still works for building OpenSCToken app. I've put a binary here for you https://github.com/OpenSC/Nightly/tree/2020-03-19_ae80fb57. Just remove the faulty App (i.e. uninstall OpenSC) and run the app from the dmg.

Mar 31 '20 16:03 frankmorgner

@herm-cb did you find the time to test the binaries?

Apr 06 '20 16:04 frankmorgner

@herm-cb did any update?

May 13 '20 19:05 frankmorgner

Hello. We are facing the same issue here. We are ready to test and validate this fix if someone can provide the binary (equivalent to https://github.com/OpenSC/Nightly/tree/2020-03-19_ae80fb57?). Best regards,

Aug 23 '21 16:08 ccauquelin

You can be the first to try. Check out "Artifacts" in the top right of the CI page https://github.com/OpenSC/OpenSC/pull/2399/checks?check_run_id=3460005977

Aug 31 '21 14:08 frankmorgner

I have downloaded this artifact (contains a OpenSC-0.22.0.dmg). Then uninstalled the OpenSC 0.22.0 previously installed and install the new one and run the test.

Unfortunately: `ccauquelin test % ./serial_codesign_test.sh 120b89b2c55c2ab480a96209513d20a871afeef9
text1.txt: replacing existing signature text2.txt: replacing existing signature text3.txt: replacing existing signature text4.txt: replacing existing signature text5.txt: replacing existing signature text6.txt: replacing existing signature text7.txt: replacing existing signature text8.txt: replacing existing signature

ccauquelin test % ./parallel_codesign_test.sh 120b89b2c55c2ab480a96209513d20a871afeef9 ccauquelin test % text1.txt: replacing existing signature text3.txt: replacing existing signature text5.txt: replacing existing signature text2.txt: replacing existing signature text8.txt: replacing existing signature text6.txt: replacing existing signature text7.txt: replacing existing signature text4.txt: replacing existing signature text1.txt: errSecInternalComponent text3.txt: errSecInternalComponent text5.txt: errSecInternalComponent text2.txt: errSecInternalComponent text8.txt: errSecInternalComponent text6.txt: errSecInternalComponent text7.txt: errSecInternalComponent text4.txt: errSecInternalComponent`

Aug 31 '21 16:08 ccauquelin

Hmm, would it be possible to create a test that doesn't involve codesign+smart card usage? That would allow me to reproduce this problem locally...

Sep 09 '21 08:09 frankmorgner