Discussion:
[TrouSerS-users] Tspi_NV_DefineSpace failed: 0x00000015 - layer=tpm, code=0015 (21), Insufficient TPM resources
Conor Lennon
2014-02-12 10:25:41 UTC
Permalink
Hi,

I have installed trousers-0.3.11.2
When I run tpm-luks-init I get an "Insufficient TPM resources" from
tpm_nvdefine, so I enabled debug in trousers.
I now see the following output from tpm_nvdefine:

LOG_DEBUG TSPI tsp_tcsi_param.c:102 Got no value inside environment var
TSS_TCSD_HOSTNAME.
LOG_DEBUG TSPI tsp_tcsi_param.c:158 Hostname localhost will be used
LOG_DEBUG TSPI obj_context.c:50 Hostname to be used by the context is
localhost.
LOG_DEBUG TSPI obj_context.c:202 context->machineName: localhost.
LOG_DEBUG TSPI rpc/tcstp/rpc.c:480 Retrieving address information from
host: localhost
LOG_WARNING TSPI rpc/tcstp/rpc.c:490 WARNING: Got a list of valid IPs
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:44 RPC_OpenContext_TP: Received TCS
Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_auth.c:70 RPC_OSAP_TP: TCS Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_nv.c:39 RPC_NV_DefineOrReleaseSpace_TP: TCS
Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_nv.c:69 RPC_NV_DefineOrReleaseSpace_TP:
result=21
Tspi_NV_DefineSpace failed: 0x00000015 - layer=tpm, code=0015 (21),
Insufficient TPM resources
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:60 RPC_CloseContext_TP: TCS
Context: 0xa0938800
LOG_RETERR TSPI tspi_context.c:113: 0x126


I've made the following changes to tcs_utils.c
replaced
LogData("UnloadBlob_Tag:", (temp));
with
LogDebug("UnloadBlob_Tag: %d", (temp));

replaced
LogData("UnloadBlob_Header, size:", *size);
with
LogDebug("UnloadBlob_Header, size: %d", *size);

replaced
LogData("UnloadBlob_Header, returnCode:",
Decode_UINT32(&blob[6]));
with
LogDebug("UnloadBlob_Header, returnCode: %d",
Decode_UINT32(&blob[6]));


I see the following output from tcsd

TCSD svrside.c:539 accepted socket 6
TCSD svrside.c:514 Waiting for connections
TCSD tcsd_threads.c:232 total_recv_size 28, buf_size 1024, recd_so_far 28
TCSD tcsd_threads.c:284 Rx'd packet
TCSD TCS rpc/tcstp/rpc.c:581 Dispatching ordinal 1 (OpenContext)
TCSD TCS rpc/tcstp/rpc_context.c:37 tcs_wrap_OpenContext: thread
-1208972400
TCSD TCS rpc/tcstp/rpc_context.c:53 New context is 0xa093d601
TCSD tcsd_threads.c:313 Sending 0x26 bytes back
TCSD tcsd_threads.c:232 total_recv_size 44, buf_size 1024, recd_so_far 28
TCSD tcsd_threads.c:277 recv_chunk_size 16 recd_so_far 28
TCSD tcsd_threads.c:284 Rx'd packet
TCSD TCS rpc/tcstp/rpc.c:581 Dispatching ordinal 46 (GetCapability)
TCSD TCS rpc/tcstp/rpc_caps_tpm.c:47 tcs_wrap_GetCapability: thread
-1208972400d context a093d601
TCSD TCS tcsi_caps_tpm.c:43 Entering Get Cap
To TPM: 00 C1 00 00 00 12 00 00 00 65 00 00 00 0D 00 00
To TPM: 00 00
TCSD TDDL tddl.c:171 Calling write to driver
Richard
2014-02-18 21:18:30 UTC
Permalink
Connor,

Can you provide the output of the tpm_nvinfo?
Post by Conor Lennon
Hi,
I have installed trousers-0.3.11.2
When I run tpm-luks-init I get an "Insufficient TPM resources" from
tpm_nvdefine, so I enabled debug in trousers.
LOG_DEBUG TSPI tsp_tcsi_param.c:102 Got no value inside environment var
TSS_TCSD_HOSTNAME.
LOG_DEBUG TSPI tsp_tcsi_param.c:158 Hostname localhost will be used
LOG_DEBUG TSPI obj_context.c:50 Hostname to be used by the context is
localhost.
LOG_DEBUG TSPI obj_context.c:202 context->machineName: localhost.
LOG_DEBUG TSPI rpc/tcstp/rpc.c:480 Retrieving address information from
host: localhost
LOG_WARNING TSPI rpc/tcstp/rpc.c:490 WARNING: Got a list of valid IPs
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:44 RPC_OpenContext_TP: Received TCS
Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_auth.c:70 RPC_OSAP_TP: TCS Context: 0xa0938800
LOG_DEBUG TSPI rpc/tcstp/rpc_nv.c:39 RPC_NV_DefineOrReleaseSpace_TP: TCS
Context: 0xa0938800
result=21
Tspi_NV_DefineSpace failed: 0x00000015 - layer=tpm, code=0015 (21),
Insufficient TPM resources
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:60 RPC_CloseContext_TP: TCS
Context: 0xa0938800
LOG_RETERR TSPI tspi_context.c:113: 0x126
I've made the following changes to tcs_utils.c
replaced
LogData("UnloadBlob_Tag:", (temp));
with
LogDebug("UnloadBlob_Tag: %d", (temp));
replaced
LogData("UnloadBlob_Header, size:", *size);
with
LogDebug("UnloadBlob_Header, size: %d", *size);
replaced
LogData("UnloadBlob_Header, returnCode:",
Decode_UINT32(&blob[6]));
with
LogDebug("UnloadBlob_Header, returnCode: %d",
Decode_UINT32(&blob[6]));
I see the following output from tcsd
TCSD svrside.c:539 accepted socket 6
TCSD svrside.c:514 Waiting for connections
TCSD tcsd_threads.c:232 total_recv_size 28, buf_size 1024, recd_so_far 28
TCSD tcsd_threads.c:284 Rx'd packet
TCSD TCS rpc/tcstp/rpc.c:581 Dispatching ordinal 1 (OpenContext)
TCSD TCS rpc/tcstp/rpc_context.c:37 tcs_wrap_OpenContext: thread
-1208972400
TCSD TCS rpc/tcstp/rpc_context.c:53 New context is 0xa093d601
TCSD tcsd_threads.c:313 Sending 0x26 bytes back
TCSD tcsd_threads.c:232 total_recv_size 44, buf_size 1024, recd_so_far 28
TCSD tcsd_threads.c:277 recv_chunk_size 16 recd_so_far 28
TCSD tcsd_threads.c:284 Rx'd packet
TCSD TCS rpc/tcstp/rpc.c:581 Dispatching ordinal 46 (GetCapability)
TCSD TCS rpc/tcstp/rpc_caps_tpm.c:47 tcs_wrap_GetCapability: thread
-1208972400d context a093d601
TCSD TCS tcsi_caps_tpm.c:43 Entering Get Cap
To TPM: 00 C1 00 00 00 12 00 00 00 65 00 00 00 0D 00 00
To TPM: 00 00
TCSD TDDL tddl.c:171 Calling write to driver
Conor Lennon
2014-02-19 09:20:03 UTC
Permalink
output of tpm_nvinfo compiled with debug:

# tpm_nvinfo
LOG_DEBUG TSPI tsp_tcsi_param.c:102 Got no value inside environment var
TSS_TCSD_HOSTNAME.
LOG_DEBUG TSPI tsp_tcsi_param.c:158 Hostname localhost will be used
LOG_DEBUG TSPI obj_context.c:50 Hostname to be used by the context is
localhost.
LOG_DEBUG TSPI obj_context.c:202 context->machineName: localhost.
LOG_DEBUG TSPI rpc/tcstp/rpc.c:480 Retrieving address information from
host: localhost
LOG_WARNING TSPI rpc/tcstp/rpc.c:490 WARNING: Got a list of valid IPs
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:44 RPC_OpenContext_TP: Received TCS
Context: 0xa09f3400
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
NVRAM index : 0x10000001 (268435457)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00001002 (WRITEALL|OWNERWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 20 (0x14)

NVRAM index : 0x1000f000 (268496896)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00020002 (OWNERREAD|OWNERWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 1129 (0x469)

NVRAM index : 0x50000002 (1342177282)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : 0x18
Permissions : 0x00000000 ()
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 64 (0x40)

NVRAM index : 0x50000001 (1342177281)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00002000 (WRITEDEFINE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : TRUE
Size : 54 (0x36)

NVRAM index : 0x00000002 (2)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)

NVRAM index : 0x00000003 (3)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)

NVRAM index : 0x00000004 (4)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)

NVRAM index : 0x00000005 (5)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)

NVRAM index : 0x00000006 (6)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)

NVRAM index : 0x00000007 (7)
LOG_DEBUG TSPI rpc/tcstp/rpc_caps_tpm.c:40 RPC_GetTPMCapability_TP: TCS
Context: 0xa09f3400
PCR read selection:
Localities : ALL
PCR write selection:
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)

LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:60 RPC_CloseContext_TP: TCS
Context: 0xa09f3400
LOG_RETERR TSPI tspi_context.c:113: 0x126
Post by Richard
Connor,
Can you provide the output of the tpm_nvinfo?
Richard
2014-02-25 19:39:40 UTC
Permalink
Connor,

I'm trying to reproduce this using a software TPM, since mine doesn't
have NVRAM space. But from the look of it, the tpm-luks-init is trying
to use too many resources or another programming is sharing the
resources with it. Do you have any other application which uses TPM -
specifically, the tpm nvram?
Post by Conor Lennon
# tpm_nvinfo
LOG_DEBUG TSPI tsp_tcsi_param.c:102 Got no value inside environment
var TSS_TCSD_HOSTNAME.
LOG_DEBUG TSPI tsp_tcsi_param.c:158 Hostname localhost will be used
LOG_DEBUG TSPI obj_context.c:50 Hostname to be used by the context is
localhost.
LOG_DEBUG TSPI obj_context.c:202 context->machineName: localhost.
LOG_DEBUG TSPI rpc/tcstp/rpc.c:480 Retrieving address information from
host: localhost
LOG_WARNING TSPI rpc/tcstp/rpc.c:490 WARNING: Got a list of valid IPs
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:44 RPC_OpenContext_TP: Received
TCS Context: 0xa09f3400
TCS Context: 0xa09f3400
NVRAM index : 0x10000001 (268435457)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00001002 (WRITEALL|OWNERWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 20 (0x14)
NVRAM index : 0x1000f000 (268496896)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00020002 (OWNERREAD|OWNERWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 1129 (0x469)
NVRAM index : 0x50000002 (1342177282)
TCS Context: 0xa09f3400
Localities : ALL
Localities : 0x18
Permissions : 0x00000000 ()
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 64 (0x40)
NVRAM index : 0x50000001 (1342177281)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00002000 (WRITEDEFINE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : TRUE
Size : 54 (0x36)
NVRAM index : 0x00000002 (2)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)
NVRAM index : 0x00000003 (3)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)
NVRAM index : 0x00000004 (4)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)
NVRAM index : 0x00000005 (5)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)
NVRAM index : 0x00000006 (6)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)
NVRAM index : 0x00000007 (7)
TCS Context: 0xa09f3400
Localities : ALL
Localities : ALL
Permissions : 0x00040004 (AUTHREAD|AUTHWRITE)
bReadSTClear : FALSE
bWriteSTClear : FALSE
bWriteDefine : FALSE
Size : 32 (0x20)
LOG_DEBUG TSPI rpc/tcstp/rpc_context.c:60 RPC_CloseContext_TP: TCS
Context: 0xa09f3400
LOG_RETERR TSPI tspi_context.c:113: 0x126
On Tue, 18 Feb 2014 21:18:30 -0000, Richard
Post by Richard
Connor,
Can you provide the output of the tpm_nvinfo?
Conor Lennon
2014-02-27 13:38:44 UTC
Permalink
I managed to get to the bottom of that problem.
It was indeed that there were too many resources in use.
Once I freed some up Tspi_NV_DefineSpace completed successfully.

I now have the following situation:

It has an encrypted root file system and an encrypted swap partition.
The machine boots with TrustedGrub and TrustedGrub detects the TPM module.
tpm-luks is installed and tpm-luks-init completed successfully.
tpm-luks-init successfully saved encryption keys for each of the two
encrypted partitions to the TPM module.
It all looks good.
However, linux still prompts for the encryption password at boot-time.

Any suggestions on where I should be looking for the source of the problem?

The following is run on boot:
cryptsetup luksOpen /dev/sda2 rootcrypt

Is there something different I should be doing to read the key from the
TPM?
The cryptsetup FAQ suggests that I should get cryptsetup read the key from
STDIN that is written by something that reads the value from the TPM.
However, I haven't found any examples of this anywhere.

Thanks,
Conor
Post by Richard
Connor,
I'm trying to reproduce this using a software TPM, since mine doesn't
have NVRAM space. But from the look of it, the tpm-luks-init is tryingto
use too many resources or another programming is sharing theresources
with it. Do you have any other application which uses TPM -specifically,
the tpm nvram?
Loading...