Closed xirami closed 2 years ago
First, double-check that /etc/aziot/keyd/config.d/00-super.toml
has the same [pkcs11]
section with the same values.
If it does, try dumping the raw values by running with pkcs11spy as the PKCS#11 library, first with pkcs11-tool, then with keyd itself:
apt install opensc-pkcs11
Run pkcs11-tool with pkcs11spy and post the output.
sudo -u aziotks PKCS11SPY=/usr/local/lib/libtpm2_pkcs11.so pkcs11-tool --module /usr/lib/<whatever>/pkcs11/pkcs11-spy.so -IOT
In the aziot-keyd config, change the pkcs11_lib_path
to /usr/lib/<whatever>/pkcs11/pkcs11-spy.so
Run systemctl edit aziot-keyd.service
, and in the editor that opens, write:
[Service]
Environment=PKCS11SPY=/usr/local/lib/libtpm2_pkcs11.so
iotedge system restart
to stop the services and restart edged, and then check the keyd logs again.spy output
onsp@dfa-eg-onsp-002:~$ sudo -u aziotks PKCS11SPY=/usr/local/lib/libtpm2_pkcs11.so pkcs11-tool --module /usr/lib/x86_64-linux-gnu/pkcs11-spy.so -IOT
*************** OpenSC PKCS#11 spy *****************
Loaded: "/usr/local/lib/libtpm2_pkcs11.so"
0: C_GetFunctionList
2021-11-18 19:04:49.429
Returned: 0 CKR_OK
1: C_Initialize
2021-11-18 19:04:49.430
[in] pInitArgs = (nil)
WARNING:fapi:src/tss2-fapi/ifapi_io.c:282:ifapi_io_check_create_dir() Directory /usr/local/var/run/tpm2-tss/eventlog/ does not exist, creating
ERROR:fapi:src/tss2-fapi/ifapi_helpers.c:986:create_dirs() mkdir not possible: -1 /usr/local/var/
ERROR:fapi:src/tss2-fapi/ifapi_helpers.c:1013:ifapi_create_dirs() ErrorCode (0x0006000b) Create directories for /usr/local/var/run/tpm2-tss/eventlog/
ERROR:fapi:src/tss2-fapi/ifapi_io.c:285:ifapi_io_check_create_dir() ErrorCode (0x0006000b) Directory /usr/local/var/run/tpm2-tss/eventlog/ can't be created.
ERROR:fapi:src/tss2-fapi/ifapi_eventlog.c:44:ifapi_eventlog_initialize() ErrorCode (0x0006000b) Directory check/creation failed for /usr/local/var/run/tpm2-tss/eventlog/
ERROR:fapi:src/tss2-fapi/api/Fapi_Initialize.c:199:Fapi_Initialize_Finish() Initializing eventlog module ErrorCode (0x0006000b)
Returned: 0 CKR_OK
2: C_GetInfo
2021-11-18 19:04:49.617
[out] pInfo:
cryptokiVersion: 2.40
manufacturerID: 'tpm2-software.github.io '
flags: 0
libraryDescription: 'TPM2.0 Cryptoki '
libraryVersion: 0.0
Returned: 0 CKR_OK
Cryptoki version 2.40
Manufacturer tpm2-software.github.io
Library TPM2.0 Cryptoki (ver 0.0)
3: C_GetSlotList
2021-11-18 19:04:49.617
[in] tokenPresent = 0x1
[out] pSlotList:
Count is 2
[out] *pulCount = 0x2
Returned: 0 CKR_OK
4: C_GetSlotList
2021-11-18 19:04:49.617
[in] tokenPresent = 0x1
[out] pSlotList:
Slot 1
Slot 2
[out] *pulCount = 0x2
Returned: 0 CKR_OK
Available slots:
5: C_GetSlotInfo
2021-11-18 19:04:49.617
[in] slotID = 0x1
[out] pInfo:
slotDescription: 'dfapairs '
'Intel '
manufacturerID: 'Intel '
hardwareVersion: 1.16
firmwareVersion: 45.9
flags: 5
CKF_TOKEN_PRESENT
CKF_HW_SLOT
Returned: 0 CKR_OK
Slot 0 (0x1): dfapairs Intel
6: C_GetTokenInfo
2021-11-18 19:04:49.617
[in] slotID = 0x1
[out] pInfo:
label: 'dfapairs '
manufacturerID: 'Intel '
model: 'Intel '
serialNumber: '0000000000000000'
ulMaxSessionCount: 1024
ulSessionCount: 0
ulMaxRwSessionCount: 1024
ulRwSessionCount: 0
ulMaxPinLen: 128
ulMinPinLen: 0
ulTotalPublicMemory: -1
ulFreePublicMemory: -1
ulTotalPrivateMemory: -1
ulFreePrivateMemory: -1
hardwareVersion: 1.16
firmwareVersion: 45.9
time: '2021111819044900'
flags: 40d
CKF_RNG
CKF_LOGIN_REQUIRED
CKF_USER_PIN_INITIALIZED
CKF_TOKEN_INITIALIZED
Returned: 0 CKR_OK
token label : dfapairs
token manufacturer : Intel
token model : Intel
token flags : login required, rng, token initialized, PIN initialized
hardware version : 1.16
firmware version : 45.9
serial num : 0000000000000000
pin min/max : 0/128
7: C_GetSlotInfo
2021-11-18 19:04:49.617
[in] slotID = 0x2
[out] pInfo:
slotDescription: ' '
'Intel '
manufacturerID: 'Intel '
hardwareVersion: 1.16
firmwareVersion: 45.9
flags: 5
CKF_TOKEN_PRESENT
CKF_HW_SLOT
Returned: 0 CKR_OK
Slot 1 (0x2): Intel
8: C_GetTokenInfo
2021-11-18 19:04:49.618
[in] slotID = 0x2
[out] pInfo:
label: ' '
manufacturerID: 'Intel '
model: 'Intel '
serialNumber: '0000000000000000'
ulMaxSessionCount: 1024
ulSessionCount: 0
ulMaxRwSessionCount: 1024
ulRwSessionCount: 0
ulMaxPinLen: 128
ulMinPinLen: 0
ulTotalPublicMemory: -1
ulFreePublicMemory: -1
ulTotalPrivateMemory: -1
ulFreePrivateMemory: -1
hardwareVersion: 1.16
firmwareVersion: 45.9
time: '2021111819044900'
flags: 5
CKF_RNG
CKF_LOGIN_REQUIRED
Returned: 0 CKR_OK
token state: uninitialized
9: C_GetSlotInfo
2021-11-18 19:04:49.618
[in] slotID = 0x1
[out] pInfo:
slotDescription: 'dfapairs '
'Intel '
manufacturerID: 'Intel '
hardwareVersion: 1.16
firmwareVersion: 45.9
flags: 5
CKF_TOKEN_PRESENT
CKF_HW_SLOT
Returned: 0 CKR_OK
Using slot 0 with a present token (0x1)
10: C_OpenSession
2021-11-18 19:04:49.618
[in] slotID = 0x1
[in] flags = 0x4
pApplication=(nil)
Notify=(nil)
[out] *phSession = 0x100000000000001
Returned: 0 CKR_OK
11: C_FindObjectsInit
2021-11-18 19:04:49.618
[in] hSession = 0x100000000000001
[in] pTemplate[0]:
Returned: 0 CKR_OK
12: C_FindObjects
2021-11-18 19:04:49.618
[in] hSession = 0x100000000000001
[in] ulMaxObjectCount = 0x1
[out] ulObjectCount = 0x0
Returned: 0 CKR_OK
13: C_FindObjectsFinal
2021-11-18 19:04:49.618
[in] hSession = 0x100000000000001
Returned: 0 CKR_OK
14: C_CloseSession
2021-11-18 19:04:49.618
[in] hSession = 0x100000000000001
Returned: 0 CKR_OK
15: C_Finalize
2021-11-18 19:04:49.618
Returned: 0 CKR_OK
then issued sudo systemctl edit aziot-keyd.service
...
file was empty, so entered as above:
issued iotedge system restart
... changed to:
Nov 18 19:13:43 dfa-eg-onsp-002 systemd[1]: Started Azure IoT Keys Service.
Nov 18 19:13:43 dfa-eg-onsp-002 systemd-journald[449]: Suppressed 187936 messages from aziot-keyd.service
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [INFO] - Starting service...
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [INFO] - Version - 1.2.4
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [INFO] - Loaded libaziot-keys with version 0x02000000
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: *************** OpenSC PKCS#11 spy *****************
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Loaded: "/usr/local/lib/libtpm2_pkcs11.so"
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 0: C_GetFunctionList
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.288
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 0 CKR_OK
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 1: C_Initialize
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.288
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [in] pInitArgs = 0x7fff972c8b30
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: flags: 1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: CKF_LIBRARY_CANT_CREATE_OS_THREADS
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: WARNING:fapi:src/tss2-fapi/ifapi_io.c:282:ifapi_io_check_create_dir() Directory /usr/local/var/run/tpm2-tss/eventlog/ does not exist, creating
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ERROR:fapi:src/tss2-fapi/ifapi_helpers.c:986:create_dirs() mkdir not possible: -1 /usr/local/var/
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ERROR:fapi:src/tss2-fapi/ifapi_helpers.c:1013:ifapi_create_dirs() ErrorCode (0x0006000b) Create directories for /usr/local/var/run/tpm2-tss/eventlog/
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ERROR:fapi:src/tss2-fapi/ifapi_io.c:285:ifapi_io_check_create_dir() ErrorCode (0x0006000b) Directory /usr/local/var/run/tpm2-tss/eventlog/ can't be created.
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ERROR:fapi:src/tss2-fapi/ifapi_eventlog.c:44:ifapi_eventlog_initialize() ErrorCode (0x0006000b) Directory check/creation failed for /usr/local/var/run/tpm2-tss/eventlog/
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ERROR:fapi:src/tss2-fapi/api/Fapi_Initialize.c:199:Fapi_Initialize_Finish() Initializing eventlog module ErrorCode (0x0006000b)
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 0 CKR_OK
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2: C_GetInfo
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.399
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [out] pInfo:
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: cryptokiVersion: 2.40
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: manufacturerID: 'tpm2-software.github.io '
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: flags: 0
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: libraryDescription: 'TPM2.0 Cryptoki '
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: libraryVersion: 0.0
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 0 CKR_OK
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 3: C_GetSlotList
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.399
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [in] tokenPresent = 0x1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 336 CKR_BUFFER_TOO_SMALL
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 4: C_GetSlotList
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.399
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [in] tokenPresent = 0x1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [out] pSlotList:
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Slot 1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [out] *pulCount = 0x1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 0 CKR_OK
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 5: C_GetTokenInfo
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.399
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [in] slotID = 0x1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: [out] pInfo:
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: label: ' '
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: manufacturerID: 'Intel '
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: model: 'Intel '
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: serialNumber: '0000000000000000'
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulMaxSessionCount: 1024
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulSessionCount: 0
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulMaxRwSessionCount: 1024
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulRwSessionCount: 0
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulMaxPinLen: 128
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulMinPinLen: 0
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulTotalPublicMemory: -1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulFreePublicMemory: -1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulTotalPrivateMemory: -1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: ulFreePrivateMemory: -1
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: hardwareVersion: 1.16
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: firmwareVersion: 45.9
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: time: '2021111819134300'
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: flags: 5
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: CKF_RNG
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: CKF_LOGIN_REQUIRED
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 0 CKR_OK
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [ERR!] - could not find a slot with a matching label
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 6: C_Finalize
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18 19:13:43.400
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: Returned: 0 CKR_OK
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [ERR!] - service encountered an error
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [ERR!] - caused by: could not set pkcs11_lib_path parameter on library: AZIOT_KEYS_RC_ERR_EXTERNAL
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 2021-11-18T19:13:43Z [ERR!] - 0: <unknown>
Nov 18 19:13:43 dfa-eg-onsp-002 aziot-keyd[2595]: 1: <unknown>
Nov 18 19:13:43 dfa-eg-onsp-002 systemd[1]: aziot-keyd.service: Main process exited, code=exited, status=1/FAILURE
Nov 18 19:13:43 dfa-eg-onsp-002 systemd[1]: aziot-keyd.service: Failed with result 'exit-code'.
First, double-check that
/etc/aziot/keyd/config.d/00-super.toml
has the same[pkcs11]
section with the same values.
Did you do this?
3. In the aziot-keyd config, change thepkcs11_lib_path
to/usr/lib/<whatever>/pkcs11/pkcs11-spy.so
Did you do this?
looks like the slot catched by spy has no label...maybe aziot-keyd
runs under different user?
Can't get list of iotedge modules....sudo iotedge list
just blocks and shows nothing...
IIRC Ubuntu's sudo
keeps the HOME
env var from the calling environment. So I wonder if when you ran tpm2_ptool init
it put the .tpm2-pkcs11
directory in your human user's $HOME
instead of aziotks
's $HOME
(/var/lib/aziot/keyd
)
First, double-check that
/etc/aziot/keyd/config.d/00-super.toml
has the same[pkcs11]
section with the same values.Did you do this?
~3. In the aziot-keyd config, change the
pkcs11_lib_path
to/usr/lib/<whatever>/pkcs11/pkcs11-spy.so
~~Did you do this?~
yes
IIRC Ubuntu's
sudo
keeps theHOME
env var from the calling environment. So I wonder if when you rantpm2_ptool init
it put the.tpm2-pkcs11
directory in your human user's$HOME
instead ofaziotks
's$HOME
(/var/lib/aziot/keyd
)
I run the script from user onsp
, who is sudoer, but without sudo.
Yes, .tpm2-pkcs11 is in /home/onsp
Yes, .tpm2-pkcs11 is in
/home/onsp
Yeah, so that's wrong then. It needs to be in /var/lib/aziot/keyd
for keyd to be able to use it.
Tested, it works (just modified slot creation script using -Hu
switch for sudo)
Many thanks for attitude and contribution @arsing
and check....
Thanks for confirming.
Based on your latest logs I guess you already figured it out, but for the sake of anyone else landing here in the future: To stop using pkcs11spy and go back to using tpm2-pkcs11.so
, change the pkcs11_lib_path
back to tpm2-pkcs11.so
, delete the systemd override file you created with systemctl edit
(likely to be /etc/systemd/system/aziot-keyd.service.d/override.conf
), run systemctl daemon-reload
so that systemd notices you deleted the override file, then iotedge system restart
.
I've B&R APC2200 installed with Ununtu 18.04 LTS. Installed latest IoT Edge 1.2.5
my
config.toml
looks like thisand I have created the slot
dfapairs
, checked with pkcs11-toolkeysd service throws this error:
iotedge check
:Thanks for help.
NOTE: In order to get things running (according to guides here https://azure.github.io/iot-identity-service/pkcs11/tpm2-pkcs11.html) I had to change owner of the
scr
folder toaziotks
, like this: