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

herm-cb · 2020-03-14T18:21:40Z

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

The text was updated successfully, but these errors were encountered:

herm-cb · 2020-03-15T04:50:01Z

OpenSC debug=3 logs here

dengert · 2020-03-15T12:06:06Z

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.

dengert · 2020-03-15T12:18:31Z

Correction should be OPENSC_DRIVER=PIV-II

herm-cb · 2020-03-15T15:31:49Z

@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

dengert · 2020-03-15T18:51:59Z

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;
   }

herm-cb · 2020-03-15T22:07:11Z

@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?

dengert · 2020-03-15T22:17:05Z

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

herm-cb · 2020-03-17T00:34:35Z

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

dengert · 2020-03-17T12:51:53Z

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?

dengert · 2020-03-17T14:04:27Z

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 #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.

herm-cb · 2020-03-17T17:24:40Z

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

dengert · 2020-03-17T17:32:04Z

You can hold off until Frank has a look.

frankmorgner · 2020-03-19T22:19:05Z

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...

fixes OpenSC#1983

frankmorgner · 2020-03-19T22:41:37Z

I've implemented a fix here #1985, but I currently don't have time to create binaries nor test it.

herm-cb · 2020-03-20T04:47:58Z

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

herm-cb · 2020-03-20T05:20:58Z

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?

mouse07410 · 2020-03-20T10:15:27Z

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.

herm-cb · 2020-03-20T19:52:37Z

@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

dengert · 2020-03-20T19:55:36Z

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.

herm-cb · 2020-03-22T04:16:58Z

@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.

herm-cb · 2020-03-22T14:19:04Z

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

LDLFLAGS=-L/usr/local/opt/openssl@1.1/lib
CPPFLAGS=-I/usr/local/opt/openssl@1.1/include
PKG_CONFIG_PATH=/usr/local/opt/openssl@1.1/lib/pkgconfig

But I'm now stuck on:

Making all in unittests
gcc -DHAVE_CONFIG_H -I. -I../../..   -I/usr/local/opt/openssl@1.1/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.

mouse07410 · 2020-03-27T19:06:14Z

@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?

frankmorgner · 2020-03-31T16:11:13Z

@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.

frankmorgner · 2020-04-06T16:11:19Z

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

frankmorgner · 2020-05-13T19:57:02Z

@herm-cb did any update?

ccauquelin · 2021-08-23T16:27:35Z

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,

fixes OpenSC#1983

frankmorgner · 2021-08-31T14:08:14Z

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

ccauquelin · 2021-08-31T16:47:59Z

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`

frankmorgner · 2021-09-09T08:57:38Z

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...

frankmorgner added a commit to frankmorgner/OpenSC that referenced this issue Mar 19, 2020

reader-cryptotokenkit: support thread-wise separation

ae80fb5

fixes OpenSC#1983

frankmorgner mentioned this issue Mar 19, 2020

reader-cryptotokenkit: support thread-wise separation #1985

Closed

5 tasks

frankmorgner added this to In progress in Release 0.21.0 Apr 8, 2020

frankmorgner linked a pull request Aug 29, 2021 that will close this issue

reader-cryptotokenkit: support thread-wise separation #2399

Draft

5 tasks

frankmorgner added a commit to frankmorgner/OpenSC that referenced this issue Aug 30, 2021

reader-cryptotokenkit: support thread-wise separation

879a32f

fixes OpenSC#1983

frankmorgner mentioned this issue Mar 8, 2022

OpenSCToken stops responding, requires restart of plugin/ctk* to clear it up #2519

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

herm-cb commented Mar 14, 2020 •

edited

herm-cb commented Mar 15, 2020

dengert commented Mar 15, 2020 •

edited

dengert commented Mar 15, 2020

herm-cb commented Mar 15, 2020

dengert commented Mar 15, 2020

herm-cb commented Mar 15, 2020

dengert commented Mar 15, 2020

herm-cb commented Mar 17, 2020

dengert commented Mar 17, 2020

dengert commented Mar 17, 2020

herm-cb commented Mar 17, 2020

dengert commented Mar 17, 2020

frankmorgner commented Mar 19, 2020

frankmorgner commented Mar 19, 2020

herm-cb commented Mar 20, 2020

herm-cb commented Mar 20, 2020

mouse07410 commented Mar 20, 2020

herm-cb commented Mar 20, 2020

dengert commented Mar 20, 2020

herm-cb commented Mar 22, 2020

herm-cb commented Mar 22, 2020

mouse07410 commented Mar 27, 2020

frankmorgner commented Mar 31, 2020

frankmorgner commented Apr 6, 2020

frankmorgner commented May 13, 2020

ccauquelin commented Aug 23, 2021

frankmorgner commented Aug 31, 2021

ccauquelin commented Aug 31, 2021

frankmorgner commented Sep 9, 2021

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

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

Comments

herm-cb commented Mar 14, 2020 • edited

Problem Description

Proposed Resolution

Steps to reproduce

Logs

herm-cb commented Mar 15, 2020

dengert commented Mar 15, 2020 • edited

dengert commented Mar 15, 2020

herm-cb commented Mar 15, 2020

dengert commented Mar 15, 2020

herm-cb commented Mar 15, 2020

dengert commented Mar 15, 2020

herm-cb commented Mar 17, 2020

dengert commented Mar 17, 2020

dengert commented Mar 17, 2020

herm-cb commented Mar 17, 2020

dengert commented Mar 17, 2020

frankmorgner commented Mar 19, 2020

frankmorgner commented Mar 19, 2020

herm-cb commented Mar 20, 2020

herm-cb commented Mar 20, 2020

mouse07410 commented Mar 20, 2020

herm-cb commented Mar 20, 2020

dengert commented Mar 20, 2020

herm-cb commented Mar 22, 2020

herm-cb commented Mar 22, 2020

mouse07410 commented Mar 27, 2020

frankmorgner commented Mar 31, 2020

frankmorgner commented Apr 6, 2020

frankmorgner commented May 13, 2020

ccauquelin commented Aug 23, 2021

frankmorgner commented Aug 31, 2021

ccauquelin commented Aug 31, 2021

frankmorgner commented Sep 9, 2021

herm-cb commented Mar 14, 2020 •

edited

dengert commented Mar 15, 2020 •

edited