[opencryptoki-users] [Fwd: Re: tpmtoken_init, set the SO PIN fail]
Brought to you by:
ebarretto
From: Michal P. <mi...@ic...> - 2007-01-25 08:13:34
|
Sorry, I didn't notice that I sent the mail only to Tom, so here it is... -------- Original Message -------- Subject: Re: [opencryptoki-users] tpmtoken_init, set the SO PIN fail Date: Fri, 19 Jan 2007 14:10:45 +0100 From: Michal Prochazka <mi...@ic...> Reply-To: mi...@ic... To: Tom Lendacky <to...@us...> References: <OF4...@us...> Hi Tom, On Thu, 2007-01-18 at 09:55 -0600, Tom Lendacky wrote: > I'm not sure what is going wrong. I pulled down the openCryptoki from > CVS, > trousers (cvs tag TROUSERS_0_2_8) and tpm-tools and rebuilt and > installed > each of them. I did a tpm_takeownership, specifying an owner password > and NO srk password (just hit enter when prompted - this is a > requirement). > I did a tpmtoken_init and provided new SO and USER passwords. > Everything > finished successfully. > > Try building everything with debugging enabled (all the configure > scripts > should support the --enable-debug flag). Run the trousers daemon in > the > foreground (tcsd -f) and then set PKCS11_API_LOG_DEBUG=1 when > executing > the tpmtoken_init command (ie. at the command prompt enter > PKCS11_API_LOG_DEBUG=1 tpmtoken_init). Be sure your syslog > configuration > will capture daemon facility debug messages. You may want to add a > line > at the top of the /etc/syslog.conf file like > "daemon.debug /var/log/cryptoki" > Post the contents and we'll see if we can't figure out what's going > wrong. Maybe I'm doing something wrong... Is there any documentation of the installation process of the tpm-pkcs11? Is it correct if I have to start the tcsd and pkcsslotd before I can do anything with the tpmtoken tools? Of course I hit enter when I was asked for SRK password. So here are the logs: tcsd -f ------- TCSD svrside.c:268 accepted socket 6 TCSD tcsd_threads.c:196 Rx'd packet TCSD tcsd_wrap.c:4645 Dispatching ordinal 1 TCSD tcsd_wrap.c:323 thread 40800940 servicing a tcs_wrap_OpenContext request TCSD tcsd_threads.c:242 Sending 0x40E bytes back TCSD tcsd_wrap.c:4645 Dispatching ordinal 12 TCSD tcsd_wrap.c:1720 thread 40800940 context a0a79e06: tcs_wrap_LoadKeyByUUID TCS tcskcm.c:546 TCSP_LoadKeyByUUID_Internal: Enter: uuid: 0x406ef7d0 auth? 0x0 *********** TCS cache.c:720 key_mgr_inc_ref_count: TCSD mem_cached handle: 0x40000000 TCS cache.c:686 Key successfully loaded by UUID w/ TCS handle: 0x40000000 TCSD tcsd_threads.c:242 Sending 0x483 bytes back TCSD tcsd_wrap.c:4645 Dispatching ordinal 9 TCSD tcsd_wrap.c:1576 thread 40800940 context a0a79e06: tcs_wrap_GetRegisteredKeyBlob TCS ps/tcsps.c:171 psfile_get_key_by_uuid: Version: 1.1.0.0 TCS ps/tcsps.c:171 psfile_get_key_by_uuid: keyUsage: 0x11 TCS ps/tcsps.c:171 psfile_get_key_by_uuid: keyFlags: 0x0 TCS ps/tcsps.c:171 psfile_get_key_by_uuid: authDatausage: 1 TCS ps/tcsps.c:171 psfile_get_key_by_uuid: pcrInfosize: 0 TCS ps/tcsps.c:171 psfile_get_key_by_uuid: encDataSize: 0 TCSD tcsd_threads.c:242 Sending 0x53D bytes back TCSD tcsd_wrap.c:4645 Dispatching ordinal 44 TCSD tcsd_wrap.c:366 thread 40800940 context a0a79e06: tcs_wrap_GetRandom TCS tcspbg.c:1713 TCSP_GetRandom_Internal: 32 bytes To TPM: 00 C1 00 00 00 0E 00 00 00 46 00 00 00 20 TDDL tddl.c:105 Calling write to driver >From TPM: 00 C4 00 00 00 2E 00 00 00 00 00 00 00 20 AC 06 >From TPM: FF 36 70 76 68 2C CD 4B 39 E6 C1 28 38 15 7D 6E >From TPM: B4 A2 78 4C BD 22 83 38 63 4A 27 58 B8 A6 TCS tcspbg.c:1735 TCSP_GetRandom_Internal: received 32 bytes from the TPM TCSD tcsd_threads.c:242 Sending 0x42E bytes back TCSD tcsd_wrap.c:4645 Dispatching ordinal 23 TCSD tcsd_wrap.c:783 thread 40800940 context a0a79e06: tcs_wrap_OIAP TCS tcspbg.c:180 Entering TCSI_OIAP To TPM: 00 C1 00 00 00 0A 00 00 00 0A TDDL tddl.c:105 Calling write to driver >From TPM: 00 C4 00 00 00 22 00 00 00 00 00 00 00 00 F1 96 >From TPM: F5 5F 60 3C 10 A6 85 F4 6B 8B 77 AF 1E E6 79 46 >From TPM: 2E 0B TCS auth_mgr.c:265 added auth for TCS a0a79e06 TPM 0 TCSD tcsd_threads.c:242 Sending 0x422 bytes back TCSD tcsd_wrap.c:4645 Dispatching ordinal 15 TCSD tcsd_wrap.c:717 thread 40800940 context a0a79e06: tcs_wrap_GetPubkey TCS tcskcm.c:746 Entering Get pub key TCS tcskcm.c:751 Auth Used TCS cache.c:200 ensureKeyIsLoaded: 0x40000000 TCS cache.c:793 mc_get_slot_by_handle: TCSD mem_cached handle: 0x40000000 TCS cache.c:205 keySlot is 40000000 TCS cache.c:972 mc_update_time_stamp: TCSD mem_cached handle: 0x40000000 TCS cache.c:230 ensureKeyIsLoaded: Exit TCS tcskcm.c:763 GetPubKey: handle: 0x40000000, slot: 0x40000000 To TPM: 00 C2 00 00 00 3B 00 00 00 21 40 00 00 00 00 00 To TPM: 00 00 0D 8C A9 33 CE 59 3C C2 FB 6E 85 32 B4 4F To TPM: AA 6C C4 82 B0 DC 00 C3 83 6C E1 C0 CF 8F 81 4A To TPM: D6 EE 81 5D E0 76 E3 F4 69 C9 D5 TDDL tddl.c:105 Calling write to driver >From TPM: 00 C4 00 00 00 0A 00 00 00 0C TCS auth_mgr.c:218 released auth for TCS a0a79e06 TPM 0 TCS auth_mgr.c:92 no threads need to be signaled. TCSD tcsd_threads.c:242 Sending 0x40B bytes back TCSD tcsd_wrap.c:4645 Dispatching ordinal 2 TCSD tcsd_wrap.c:649 thread 40800940 context a0a79e06: tcs_wrap_CloseContext TCS tcscm.c:40 Closing context A0A79E06 TCS cache.c:744 key_mgr_dec_ref_count: decrementing ref cnt for key 0x40000000 TCS tcscm.c:52 Context A0A79E06 closed TCSD tcsd_threads.c:242 Sending 0x40B bytes back TCSD tcsd_threads.c:270 The TSP has closed the socket's connection. Thread exiting. ---------------------------------------------------------------------- syslog: ------- Jan 19 14:05:33 tapio pkcsslotd: Shared memory file is /usr/local/sbin/pkcsslotd Jan 19 14:06:08 tapio openCryptokiModule[2003]: Logging enabled 1 enabled Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_GetFunctionList Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_Initialize Jan 19 14:06:08 tapio openCryptokiModule[2003]: Anchor allocated at 60d9c0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: Shared memory 1af56000 Jan 19 14:06:08 tapio openCryptokiModule[2003]: API_Register MgrProcIndc 2003 pid 0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: DL_Load_and_Init dll_location libpkcs11_tpm.so Jan 19 14:06:08 tapio openCryptokiModule[2003]: DL_LOAD Jan 19 14:06:08 tapio openCryptokiModule[2003]: Empty slot at 0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: return from STDDLL Init = 0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: DL_LOADED Looking for index 0 name libpkcs11_tpm.so Jan 19 14:06:08 tapio openCryptokiModule[2003]: DL_Load_and_Init dll_location libpkcs11_sw.so Jan 19 14:06:08 tapio openCryptokiModule[2003]: DL_LOAD Jan 19 14:06:08 tapio openCryptokiModule[2003]: Empty slot at 1 Jan 19 14:06:08 tapio openCryptokiModule[2003]: return from STDDLL Init = 0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_GetSlotList Jan 19 14:06:08 tapio openCryptokiModule[2003]: Pres 0 Count 0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_GetSlotList Jan 19 14:06:08 tapio openCryptokiModule[2003]: Pres 0 Count 2 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_GetSlotInfo Slot=0 ptr=90eb3cf0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_GetTokenInfo Jan 19 14:06:08 tapio openCryptokiModule[2003]: Slot p = 60da40 id 0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: Calling STDLL Jan 19 14:06:08 tapio openCryptokiModule[2003]: rv 0 CK_TOKEN_INFO Flags 880045 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_InitToken Jan 19 14:06:08 tapio openCryptokiModule[2003]: Called STDLL rv = 0x0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_OpenSession 0 6 0 0 90eb3f38 Jan 19 14:06:08 tapio openCryptokiModule[2003]: Called STDLL rv = 0x0 Jan 19 14:06:08 tapio openCryptokiModule[2003]: C_Login Jan 19 14:06:08 tapio openCryptokiModule[2003]: Called STDLL rv = 0x0 Jan 19 14:06:17 tapio openCryptokiModule[2003]: C_SetPIN Jan 19 14:06:17 tapio openCryptokiModule[2003]: Called STDLL rv = 0x6 Jan 19 14:06:17 tapio openCryptokiModule[2003]: C_CloseSession Jan 19 14:06:17 tapio openCryptokiModule[2003]: Called STDLL rv = 0x0 Jan 19 14:06:17 tapio openCryptokiModule[2003]: C_Finalize Jan 19 14:06:17 tapio openCryptokiModule[2003]: Terminate_All_Process_Sessions Jan 19 14:06:17 tapio openCryptokiModule[2003]: CloseAllSessions Jan 19 14:06:17 tapio openCryptokiModule[2003]: CloseAllSessions OK Jan 19 14:06:17 tapio openCryptokiModule[2003]: CloseAllSessions Jan 19 14:06:17 tapio openCryptokiModule[2003]: CloseAllSessions OK ---------------------------------------------------------------------- tpmtoken_init: -------------- tpmtoken_init LOG_DEBUG TSPI ../tcsd_api/clntside.c:58 Sending TSP packet to host localhost. LOG_DEBUG TSPI ../tcsd_api/clntside.c:74 Connecting to 127.0.0.1 LOG_DEBUG TSPI ../tcsd_api/tcstp.c:277 TCS_OpenContext_RPC_TP: Received TCS Context: 0xa0a79e06 LOG_ERR TPM_STDLL tpm_specific.c:199 ERROR: key with ID="PUBLIC ROOT KEY" not found in the store! LOG_DEBUG TSPI ../tcsd_api/tcstp.c:866 TCSP_LoadKeyByUUID_TP: TCS Context: 0xa0a79e06 LOG_DEBUG TSPI ../tcsd_api/tcstp.c:887 TCSP_LoadKeyByUUID_TP: TCS key handle: 0x40000000 LOG_DEBUG TSPI ../tcsd_api/tcstp.c:761 TCS_GetRegisteredKeyBlob_TP: TCS Context: 0xa0a79e06 LOG_ERR TPM_STDLL tpm_specific.c:199 ERROR: key with ID="PUBLIC ROOT KEY" not found in the store! A new TPM security officer password is needed. The password must be between 6 and 127 characters in length. Enter new password: Confirm password: LOG_DEBUG TSPI ../tcsd_api/tcstp.c:2595 TCSP_GetRandom_TP: TCS Context: 0xa0a79e06 LOG_DEBUG TSPI ../tcsd_api/tcstp.c:1348 TCSP_OIAP_TP: TCS Context: 0xa0a79e06 LOG_DEBUG TSPI obj_policy.c:227 Got a secret: DA 39 A3 EE 5E 6B 4B 0D 32 55 BF EF 95 60 18 90 AF D8 07 09 LOG_DEBUG TSPI ../tcsd_api/tcstp.c:1011 TCSP_GetPubKey_TP: TCS Context: 0xa0a79e06 LOG_ERR TPM_STDLL tpm_specific.c:300 ERROR: Tspi_Key_GetPubKey failed: rc=0xc LOG_ERR TPM_STDLL tpm_specific.c:1075 ERROR: token_wrap_sw_key failed. rc=0xc LOG_ERR TPM_STDLL tpm_specific.c:1731 ERROR: FAILED creating SO tree. ST MSG TPM_STDLL new_host.c:1224 whammy C_SetPIN failed: 0x00000006 (6) LOG_DEBUG TSPI ../tcsd_api/tcstp.c:355 TCS_CloseContext_TP: TCS Context: 0xa0a79e06 I see the "ERROR: Tspi_Key_GetPubKey failed" but I don't know what to do? Thanks in advance. Michal P. -- Michal Prochazka // mi...@ic... Supercomputing Center Brno Institute of Computer Science Masaryk University Botanicka 68a, 60200 Brno, CZ CESNET z.s.p.o. Zikova 4, 16200 Praha 6, CZ -- Michal Prochazka // mi...@ic... Supercomputing Center Brno Institute of Computer Science Masaryk University Botanicka 68a, 60200 Brno, CZ CESNET z.s.p.o. Zikova 4, 16200 Praha 6, CZ |