Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add more pkcs11 tests #426

Closed
wants to merge 2 commits into from
Closed

Add more pkcs11 tests #426

wants to merge 2 commits into from

Conversation

prateek-y
Copy link
Contributor

@prateek-y prateek-y commented Sep 22, 2021

Issue #, if available:

Description of changes:

  • Add support for provisioning slots and keys on softhsm
  • Remove the dependency on env variables to automate key provisioning
  • Added tests for 4 scenarios
    ** Find slot tests
    ** Find key tests (TODO: Add more key types/lengths)
    ** Login tests
    ** Session tests
  • Add support for cleaning softhsm by cleaning the token dir (No other way to achieve this, we can do better by only tracking slots we have created, not sure if it is worth it atm)
  • Not sure if key lookup should be restricted to secret keys. Open for discussion.

TEST_OUTPUT


171: Test command: /Users/prateeky/tests/aws-c-io-tests "pkcs11_lib_initialize"
171: Test timeout computed to be: 1500
171: [INFO] [2021-09-22T18:50:10Z] [00000001106875c0] [aws-c-common] - static: libnuma.so failed to load
171: [INFO] [2021-09-22T18:50:10Z] [00000001106875c0] [tls-handler] - static: initializing TLS implementation as Apple SecureTransport.
171: [INFO] [2021-09-22T18:50:10Z] [00000001106875c0] [tls-handler] - static: ALPN support detected.
171: [DEBUG] [2021-09-22T18:50:10Z] [00000001106875c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
171: [INFO] [2021-09-22T18:50:10Z] [00000001106875c0] [pkcs11] - id=0x7f8387700670: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:yes
171: [DEBUG] [2021-09-22T18:50:10Z] [00000001106875c0] [pkcs11] - id=0x7f8387700670: Unloading PKCS#11. C_Finalize:yes
171: pkcs11_lib_initialize [ OK ]

172: Test command: /Users/prateeky/tests/aws-c-io-tests "pkcs11_lib_omit_initialize"
172: Test timeout computed to be: 1500
172: [INFO] [2021-09-22T18:50:11Z] [000000011dd195c0] [aws-c-common] - static: libnuma.so failed to load
172: [INFO] [2021-09-22T18:50:11Z] [000000011dd195c0] [tls-handler] - static: initializing TLS implementation as Apple SecureTransport.
172: [INFO] [2021-09-22T18:50:11Z] [000000011dd195c0] [tls-handler] - static: ALPN support detected.
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:omit
172: [ERROR] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bd01990: C_GetInfo() failed. PKCS#11 error: CKR_CRYPTOKI_NOT_INITIALIZED (0x00000190). AWS error: AWS_IO_PKCS11_ERROR.
172: [ERROR] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bd01990: Failed to initialize PKCS#11 library from '/usr/local/lib/softhsm/libsofthsm2.so'
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bd01990: Unloading PKCS#11. C_Finalize:omit
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
172: [INFO] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bf004c0: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:yes
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:omit
172: [INFO] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bf00600: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:omit
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
172: [ERROR] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bd08010: C_Initialize() failed. PKCS#11 error: CKR_CRYPTOKI_ALREADY_INITIALIZED (0x00000191). AWS error: AWS_IO_PKCS11_ERROR.
172: [ERROR] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bd08010: Failed to initialize PKCS#11 library from '/usr/local/lib/softhsm/libsofthsm2.so'
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bd08010: Unloading PKCS#11. C_Finalize:omit
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bf00600: Unloading PKCS#11. C_Finalize:omit
172: [DEBUG] [2021-09-22T18:50:11Z] [000000011dd195c0] [pkcs11] - id=0x7fc39bf004c0: Unloading PKCS#11. C_Finalize:yes
172: pkcs11_lib_omit_initialize [ OK ]

173: Test command: /Users/prateeky/tests/aws-c-io-tests "pkcs11_find_private_key"
173: Test timeout computed to be: 1500
173: [INFO] [2021-09-22T18:50:11Z] [0000000110d685c0] [aws-c-common] - static: libnuma.so failed to load
173: [INFO] [2021-09-22T18:50:11Z] [0000000110d685c0] [tls-handler] - static: initializing TLS implementation as Apple SecureTransport.
173: [INFO] [2021-09-22T18:50:11Z] [0000000110d685c0] [tls-handler] - static: ALPN support detected.
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
173: [INFO] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:yes
173: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*The token has been initialized and is reassigned to slot 1234884086
173: Got slot: 1234884086
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=1: Session opened on slot 1234884086
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=2: Session opened on slot 1234884086
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=1: User logged in
173: [TRACE] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=1: Found private key.
173: [TRACE] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=1: Found private key.
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=1: Session closed
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=2: Session closed
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=4: Session opened on slot 1234884086
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=5: Session opened on slot 1234884086
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=6: Session opened on slot 1234884086
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=4: User logged in
173: [ERROR] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=4: Failed to choose private key, multiple objects on PKCS#11 token match search criteria.
173: [TRACE] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=4: Found private key.
173: [TRACE] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=4: Found private key.
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=4: Session closed
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=5: Session closed
173: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0 session=6: Session closed
173: [DEBUG] [2021-09-22T18:50:11Z] [0000000110d685c0] [pkcs11] - id=0x7ff7fa6010a0: Unloading PKCS#11. C_Finalize:yes
173: pkcs11_find_private_key [ OK ]

174: Test command: /Users/prateeky/tests/aws-c-io-tests "pkcs11_find_slot"
174: Test timeout computed to be: 1500
174: [INFO] [2021-09-22T18:50:11Z] [000000010b2df5c0] [aws-c-common] - static: libnuma.so failed to load
174: [INFO] [2021-09-22T18:50:11Z] [000000010b2df5c0] [tls-handler] - static: initializing TLS implementation as Apple SecureTransport.
174: [INFO] [2021-09-22T18:50:11Z] [000000010b2df5c0] [tls-handler] - static: ALPN support detected.
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
174: [INFO] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:yes
174: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 1 slots with tokens. Picking one...
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:0 label:'' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'' flags:0x00C00025 sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: The token has been initialized and is reassigned to slot 2136453745
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 2 slots with tokens. Picking one...
174: [ERROR] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Failed to choose PKCS#11 token, multiple tokens match search criteria
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 2 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 1 doesn't match 2136453745
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:2136453745 label:'label!@#$%^&*-_=+{}[]<>?,./():_1' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'c9343d0f7f57b271' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 2 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 1 because label '' doesn't match 'label!@#$%^&*-_=+{}[]<>?,./():_1'
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:2136453745 label:'label!@#$%^&*-_=+{}[]<>?,./():_1' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'c9343d0f7f57b271' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 1 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 0 doesn't match 2136453745
174: [ERROR] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Failed to find PKCS#11 token which matches search criteria
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 1 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 0 because label '' doesn't match 'label!@#$%^&*-_=+{}[]<>?,./():_1'
174: [ERROR] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Failed to find PKCS#11 token which matches search criteria
174: The token has been initialized and is reassigned to slot 465930107
174: The token has been initialized and is reassigned to slot 1890803486
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [ERROR] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Failed to choose PKCS#11 token, multiple tokens match search criteria
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 1890803486 doesn't match 465930107
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 2 doesn't match 465930107
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:465930107 label:'label!@#$%^&*()_2' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'773661fd1bc5877b' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 465930107 doesn't match 1890803486
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 2 doesn't match 1890803486
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:1890803486 label:'label!@#$%^&*()_3' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'0793b54ff0b35f1e' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 1890803486 because label 'label!@#$%^&*()_3' doesn't match 'label!@#$%^&*()_2'
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 2 because label '' doesn't match 'label!@#$%^&*()_2'
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:465930107 label:'label!@#$%^&*()_2' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'773661fd1bc5877b' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 465930107 because label 'label!@#$%^&*()_2' doesn't match 'label!@#$%^&*()_3'
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 2 because label '' doesn't match 'label!@#$%^&*()_3'
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:1890803486 label:'label!@#$%^&*()_3' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'0793b54ff0b35f1e' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 465930107 because label 'label!@#$%^&*()_2' doesn't match 'label!@#$%^&*()_3'
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 1890803486 doesn't match 465930107
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 2 doesn't match 465930107
174: [ERROR] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Failed to find PKCS#11 token which matches search criteria
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 465930107 doesn't match 1890803486
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token in slot 1890803486 because label 'label!@#$%^&*()_3' doesn't match 'label!@#$%^&*()_2'
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 2 doesn't match 1890803486
174: [ERROR] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Failed to find PKCS#11 token which matches search criteria
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 1890803486 doesn't match 465930107
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 2 doesn't match 465930107
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:465930107 label:'label!@#$%^&*()_2' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'773661fd1bc5877b' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Found 3 slots with tokens. Picking one...
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 465930107 doesn't match 1890803486
174: [TRACE] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Ignoring PKCS#11 token because slot 2 doesn't match 1890803486
174: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Selected PKCS#11 token. slot:1890803486 label:'label!@#$%^&*()_3' manufacturerID:'SoftHSM project' model:'SoftHSM v2' serialNumber:'0793b54ff0b35f1e' flags:0x0000042D sessionCount:18446744073709551615/0 rwSessionCount:18446744073709551615/0 freePublicMemory:18446744073709551615/18446744073709551615 freePrivateMemory:18446744073709551615/18446744073709551615 hardwareVersion:2.6 firmwareVersion:2.6
174: [DEBUG] [2021-09-22T18:50:11Z] [000000010b2df5c0] [pkcs11] - id=0x7faec2f009a0: Unloading PKCS#11. C_Finalize:yes
174: pkcs11_find_slot [ OK ]

175: Test command: /Users/prateeky/tests/aws-c-io-tests "pkcs11_session_tests"
175: Test timeout computed to be: 1500
175: [INFO] [2021-09-22T18:50:11Z] [000000010d1d55c0] [aws-c-common] - static: libnuma.so failed to load
175: [INFO] [2021-09-22T18:50:11Z] [000000010d1d55c0] [tls-handler] - static: initializing TLS implementation as Apple SecureTransport.
175: [INFO] [2021-09-22T18:50:11Z] [000000010d1d55c0] [tls-handler] - static: ALPN support detected.
175: [DEBUG] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
175: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[INFO] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:yes
175: [ERROR] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0: C_OpenSession() failed. PKCS#11 error: CKR_SLOT_ID_INVALID (0x00000003). AWS error: AWS_IO_PKCS11_ERROR.
175: The token has been initialized and is reassigned to slot 1722515926
175: Got slot: 1722515926
175: [DEBUG] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0 session=1: Session opened on slot 1722515926
175: [DEBUG] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0 session=2: Session opened on slot 1722515926
175: [DEBUG] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0 session=1: Session closed
175: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[DEBUG] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0 session=2: Session closed
175: [DEBUG] [2021-09-22T18:50:11Z] [000000010d1d55c0] [pkcs11] - id=0x7f8314f002b0: Unloading PKCS#11. C_Finalize:yes
175: pkcs11_session_tests [ OK ]

176: Test command: /Users/prateeky/tests/aws-c-io-tests "pkcs11_login_tests"
176: Test timeout computed to be: 1500
176: [INFO] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [aws-c-common] - static: libnuma.so failed to load
176: [INFO] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [tls-handler] - static: initializing TLS implementation as Apple SecureTransport.
176: [INFO] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [tls-handler] - static: ALPN support detected.
176: [DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - Loading PKCS#11. file:'/usr/local/lib/softhsm/libsofthsm2.so' C_Initialize:yes
176: [INFO] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040: PKCS#11 loaded. file:'/usr/local/lib/softhsm/libsofthsm2.so' cryptokiVersion:2.40 manufacturerID:'SoftHSM' flags:0x00000000 libraryDescription:'Implementation of PKCS11' libraryVersion:2.6 C_Initialize:yes
176: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*The token has been initialized and is reassigned to slot 520941599
176: Got slot: 520941599
176: [ERROR] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=1: C_Login() failed. PKCS#11 error: CKR_SESSION_HANDLE_INVALID (0x000000B3). AWS error: AWS_IO_PKCS11_ERROR.
176: [DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=1: Session opened on slot 520941599
176: [ERROR] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=1: C_Login() failed. PKCS#11 error: CKR_PIN_INCORRECT (0x000000A0). AWS error: AWS_IO_PKCS11_ERROR.
176: [DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=1: User logged in
176: [ERROR] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=1: C_Login() failed. PKCS#11 error: CKR_USER_ALREADY_LOGGED_IN (0x00000100). AWS error: AWS_IO_PKCS11_ERROR.
176: [DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=2: Session opened on slot 520941599
176: [ERROR] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=2: C_Login() failed. PKCS#11 error: CKR_USER_ALREADY_LOGGED_IN (0x00000100). AWS error: AWS_IO_PKCS11_ERROR.
176: [DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=1: Session closed
176: [ERROR] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=2: C_Login() failed. PKCS#11 error: CKR_USER_ALREADY_LOGGED_IN (0x00000100). AWS error: AWS_IO_PKCS11_ERROR.
176: [DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040 session=2: Session closed
176: Executing command: rm -rf /usr/local/var/lib/softhsm/tokens/*[DEBUG] [2021-09-22T18:50:11Z] [000000011c5ef5c0] [pkcs11] - id=0x7fd88cd03040: Unloading PKCS#11. C_Finalize:yes
176: pkcs11_login_tests [ OK ]

100% tests passed, 0 tests failed out of 6

Total Test time (real) =   1.44 sec
Process finished with exit code 0

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

@prateek-y prateek-y marked this pull request as draft September 22, 2021 19:39
@prateek-y prateek-y marked this pull request as ready for review September 22, 2021 19:40
@@ -665,7 +642,7 @@ int aws_pkcs11_lib_find_private_key(
bool must_finalize_search = false;

/* set up search attributes */
CK_OBJECT_CLASS key_class = CKO_PRIVATE_KEY;
CK_OBJECT_CLASS key_class = CKO_SECRET_KEY;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What's the difference between CKO_PRIVATE_KEY and CKO_SECRET_KEY?
is a PRIVATE_KEY also qualify as a SECRET_KEY?

The tests were passing when I created the private key via:
softhsm2 --import tests/resources/unittests.p8
and searched for a CKO_PRIVATE_KEY

does CKO_SECRET_KEY also work when searching for keys created via the --import command?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As discussed offline, its basically the symmetric key which does not have a public key/cert associated with it. I will revert back to asymmetric key.

tests/pkcs11_test.c Show resolved Hide resolved
tests/pkcs11_test.c Outdated Show resolved Hide resolved
if (token_dir[s_pkcs11_tester.token_dir->len - 1] == '/') {
sprintf(cmd, "rm -rf %s*", token_dir);
} else {
sprintf(cmd, "rm -rf %s/*", token_dir);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this isn't cross-platform, but believe it or not we have a code-review in the works right now that adds cross-platform directory obliteration:
awslabs/aws-c-common#830

anyway, that review isn't merged. This is fine for now. we'll use the cross-platform stuff once it's available

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks

sprintf(cmd, "rm -rf %s/*", token_dir);
}
printf("Executing command: %s", cmd);
system(cmd);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

check that system() returns 0 ASSERT_SUCCESS(system(cmd))

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

or use our cross-platform stuff, but it's a lot of boilerplate
https://github.com/awslabs/aws-c-common/blob/main/include/aws/common/process.h

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nice

include/aws/io/private/pkcs11_private.h Outdated Show resolved Hide resolved
include/aws/io/private/pkcs11_private.h Outdated Show resolved Hide resolved
tests/pkcs11_test.c Outdated Show resolved Hide resolved
tests/pkcs11_test.c Outdated Show resolved Hide resolved
aws_pkcs11_lib_release(pkcs11_lib);
s_pkcs11_tester_clean_up();
return AWS_OP_SUCCESS;
}
AWS_TEST_CASE(pkcs11_find_private_key, s_test_pkcs11_find_private_key)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if you can break tests up at all, please do so

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will do that

graebm added a commit that referenced this pull request Sep 23, 2021
This is necessary for incoming tests: #426
It's also nice to use the typedefs privately, instead of uint64_t for everything.
@graebm graebm deleted the branch awslabs:pkcs11-yup September 23, 2021 17:24
@graebm graebm closed this Sep 23, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants