I cleared TPM hardware, resetted it and upgraded xen to 4.5.0. But the same
problem still exists.
~# tpm_takeownership
Enter owner password:
Confirm password:
Enter SRK password:
Confirm password:
Tspi_TPM_TakeOwnership failed: 0x00002004 - layer=tcs, code=0004 (4),
Internal software error
Here is my vtpmmgr / vtpm instance log.
*vtpmmgr:*
Xen Minimal OS!
start_info: 0xea000(VA)
nr_pages: 0x8000
shared_inf: 0xdb49c000(MA)
pt_base: 0xed000(VA)
nr_pt_frames: 0x5
mfn_list: 0xaa000(VA)
mod_start: 0x0(VA)
mod_len: 0
flags: 0x0
cmd_line:
stack: 0x68d00-0x88d00
MM: Init
_text: 0x0(VA)
_etext: 0x44133(VA)
_erodata: 0x50000(VA)
_edata: 0x53380(VA)
stack start: 0x68d00(VA)
_end: 0xa9340(VA)
start_pfn: f5
max_pfn: 8000
Mapping memory range 0x400000 - 0x8000000
setting 0x0-0x50000 readonly
skipped 0x1000
MM: Initialise page allocator for 133000(133000)-8000000(8000000)
MM: done
Demand map pfns at 8001000-2008001000.
Heap resides at 2008002000-4008002000.
Initialising timer interface
Initialising console ... done.
gnttab_table mapped at 0x8001000.
Initialising scheduler
Thread "Idle": pointer: 0x2008002050, stack: 0x180000
Thread "xenstore": pointer: 0x2008002800, stack: 0x190000
xenbus initialised on irq 1 mfn 0x122f20
Thread "shutdown": pointer: 0x2008002fb0, stack: 0x1a0000
main.c: dummy main: start_info=0x88e00
Thread "main": pointer: 0x2008003760, stack: 0x1b0000
"main"
INFO[VTPM]: Starting vTPM manager domain
INFO[VTPM]: Option: Using tpm_tis driver
******************* BLKFRONT for device/vbd/768 **********
backend at /local/domain/0/backend/qdisk/1/768
Failed to read /local/domain/0/backend/qdisk/1/768/feature-barrier.
524288 sectors of 512 bytes
**************************
blk_open(device/vbd/768) -> 3
============= Init TPM BACK ================
Thread "tpmback-listener": pointer: 0x20080044b0, stack: 0x1c0000
============= Init TPM TIS Driver ==============
IOMEM Machine Base Address: FED40000
Enabled Localities: 0
1.2 TPM (device-id=0x0 vendor-id = 104A rev-id = 4E)
TPM interface capabilities (0x15):
Interrupt Level Low
Locality Change Int Support
Data Avail Int Support
Timeout b was adjusted to standard value.
tpm_tis_open() -> 4
INFO[TPM]: TPM_GetCapability
INFO[VTPM]: Hardware TPM:
INFO[VTPM]: version: 1 2 8 8
INFO[VTPM]: specLevel: 2
INFO[VTPM]: errataRev: 2
INFO[VTPM]: vendorID: STM
INFO[VTPM]: vendorSpecificSize: 0
INFO[VTPM]: vendorSpecific:
INFO[TPM]: TPM_GetCapability
INFO[TPM]: TPM_GetCapability
INFO[VTPM]: Flushing 1 handle(s) of type 2
INFO[TPM]: TPM_FlushSpecific
INFO[TPM]: TPM_GetCapability
INFO[TPM]: TPM_GetCapability
INFO[TPM]: TPM_GetCapability
INFO[TPM]: TPM_GetCapability
INFO[TPM]: TPM_GetRandom
INFO[TPM]: TPM_GetRandom
INFO[TPM]: TPM_OIAP
INFO[TPM]: Auth Session: 0x44c0f7 opened by TPM_OIAP.
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
INFO[TPM]: TPM_PCR_Read
TPM Manager - disk format 0
root seal: 84; sector of 13: 3924
root: 3200 v=528
itree: 36; sector of 112: 4032
group: 3560 v=3472 id=816 md=280
group seal: 72; 5 in parent: 1860; sector of 13: 3904
vtpm: 20+64; sector of 48: 4048
INFO[VTPM]: disk_read_sector 0
INFO[VTPM]: disk_read_sector 1
load_root_pre: n/n
INFO[VTPM]: Failed to read manager file. Assuming first time initialization.
INFO[TPM]: TPM_ReadPubek
INFO[TPM]: TPM_TakeOwnership
INFO[TPM]: TPM_DisablePubekRead
INFO[TPM]: TPM_OSAP
INFO[TPM]: Auth Session: 0xabc128 opened by TPM_OSAP.
INFO[TPM]: TPM_SaveState
INFO[VTPM]: Finished initialized new VTPM manager
INFO[TPM]: TPM_TerminateHandle
INFO[TPM]: Auth Session: 0xabc128 closed by TPM_TerminateHandle
INFO[VTPM]: Waiting for commands from vTPM's:
Tpmback:Info Frontend 2/0 connected
INFO[VTPM]: Passthrough: TPM_GetRandom
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: Passthrough: TPM_GetRandom
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_LoadHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
SaveHashKey with unknown UUID=7740b63c-f6e3-4db2-a94c-9c5332609ad6 -
creating in auth0 (f=1)
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
INFO[VTPM]: vtpmmgr_SaveHashKey
INFO[VTPM]: Waiting for commands from vTPM's:
*vtpm:*
Xen Minimal OS!
start_info: 0xf2000(VA)
nr_pages: 0x800
shared_inf: 0xdb49a000(MA)
pt_base: 0xf5000(VA)
nr_pt_frames: 0x5
mfn_list: 0xee000(VA)
mod_start: 0x0(VA)
mod_len: 0
flags: 0x0
cmd_line:
stack: 0xad540-0xcd540
MM: Init
_text: 0x0(VA)
_etext: 0x7f3c3(VA)
_erodata: 0x95000(VA)
_edata: 0x97bc0(VA)
stack start: 0xad540(VA)
_end: 0xedb80(VA)
start_pfn: fd
max_pfn: 800
Mapping memory range 0x400000 - 0x800000
setting 0x0-0x95000 readonly
skipped 0x1000
MM: Initialise page allocator for ff000(ff000)-800000(800000)
MM: done
Demand map pfns at 801000-2000801000.
Heap resides at 2000802000-4000802000.
Initialising timer interface
Initialising console ... done.
gnttab_table mapped at 0x801000.
Initialising scheduler
Thread "Idle": pointer: 0x2000802050, stack: 0x110000
Thread "xenstore": pointer: 0x2000802800, stack: 0x120000
xenbus initialised on irq 1 mfn 0x1e0567
Thread "shutdown": pointer: 0x2000802fb0, stack: 0x130000
main.c: dummy main: start_info=0xcd640
Thread "main": pointer: 0x2000803760, stack: 0x140000
"main"
vtpm.c:463: Info: starting TPM Emulator (1.2.0.7-475)
vtpm.c:395: Info: Startup mode is `clear'
vtpm.c:425: Info: All PCRs initialized to default values
vtpm.c:429: Info: TPM Maintenance Commands disabled
vtpm.c:439: Info: Log level set to (null)
============= Init TPM BACK ================
Thread "tpmback-listener": pointer: 0x2000804380, stack: 0x150000
============= Init TPM Front ================
Tpmfront:Info Waiting for backend connection..
Tpmfront:Info Backend Connected
Tpmfront:Info Initialization Completed successfully
vtpmblk.c:34: Info: Initializing persistent NVM storage
******************* BLKFRONT for device/vbd/768 **********
backend at /local/domain/0/backend/qdisk/2/768
Failed to read /local/domain/0/backend/qdisk/2/768/feature-barrier.
32768 sectors of 512 bytes
**************************
blk_open(device/vbd/768) -> 3
vtpm.c:210: Info: VTPM Initializing
tpm_cmd_handler.c:4187: Debug: tpm_emulator_init(1, 0x00000007)
vtpm_cmd.c:155: Info: Requesting Encryption key from backend
vtpm_cmd.c:164: Error: VTPM_LoadHashKey() failed with error code (3)
vtpm_cmd.c:175: Error: VTPM_LoadHashKey failed
tpm_data.c:122: Info: initializing TPM data to default values
tpm_startup.c:29: Info: TPM_Init()
tpm_testing.c:243: Info: TPM_SelfTestFull()
tpm_testing.c:39: Debug: tpm_test_prng()
tpm_testing.c:69: Debug: Monobit: 9962
tpm_testing.c:70: Debug: Poker: 13.6
tpm_testing.c:71: Debug: run_1: 2504, 2485
tpm_testing.c:72: Debug: run_2: 1217, 1274
tpm_testing.c:73: Debug: run_3: 643, 614
tpm_testing.c:74: Debug: run_4: 328, 336
tpm_testing.c:75: Debug: run_5: 165, 147
tpm_testing.c:76: Debug: run_6+: 146, 146
tpm_testing.c:77: Debug: run_34: 0
tpm_testing.c:111: Debug: tpm_test_sha1()
tpm_testing.c:157: Debug: tpm_test_hmac()
tpm_testing.c:184: Debug: tpm_test_rsa_EK()
tpm_testing.c:186: Debug: tpm_rsa_generate_key()
tpm_testing.c:191: Debug: testing endorsement key
tpm_testing.c:197: Debug: tpm_rsa_sign(RSA_SSA_PKCS1_SHA1)
tpm_testing.c:200: Debug: tpm_rsa_verify(RSA_SSA_PKCS1_SHA1)
tpm_testing.c:203: Debug: tpm_rsa_sign(RSA_SSA_PKCS1_DER)
tpm_testing.c:206: Debug: tpm_rsa_verify(RSA_SSA_PKCS1_DER)
tpm_testing.c:210: Debug: tpm_rsa_encrypt(RSA_ES_PKCSV15)
tpm_testing.c:214: Debug: tpm_rsa_decrypt(RSA_ES_PKCSV15)
tpm_testing.c:218: Debug: verify plain text
tpm_testing.c:221: Debug: tpm_rsa_encrypt(RSA_ES_OAEP_SHA1)
tpm_testing.c:225: Debug: tpm_rsa_decrypt(RSA_ES_OAEP_SHA1)
tpm_testing.c:229: Debug: verify plain text
tpm_testing.c:261: Info: Self-Test succeeded
tpm_startup.c:43: Info: TPM_Startup(1)
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:148: Debug: [TPM_CAP_PROP_TIS_TIMEOUT]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=0
ssize=8388608
Tpmback:Info Frontend 3/0 connected
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:199: Debug: [TPM_CAP_PROP_DURATION]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3880: Debug: [TPM_ORD_PCRRead]
tpm_integrity.c:58: Info: TPM_PCRRead()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3875: Debug: [TPM_ORD_Extend]
tpm_integrity.c:39: Info: TPM_Extend()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:778: Debug: [TPM_CAP_VERSION_VAL]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:701: Debug: [TPM_CAP_ORD]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:701: Debug: [TPM_CAP_ORD]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:74: Debug: [TPM_CAP_PROP_PCR]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:78: Debug: [TPM_CAP_PROP_DIR]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:86: Debug: [TPM_CAP_PROP_KEYS]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:82: Debug: [TPM_CAP_PROP_MANUFACTURER]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
tpm_capability.c:114: Debug: [TPM_CAP_PROP_MAX_AUTHSESS]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x2000809680 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3630: Debug: [TPM_ORD_GetCapability]
tpm_capability.c:697: Info: TPM_GetCapability()
tpm_capability.c:725: Debug: [TPM_CAP_KEY_HANDLE]
tpm_capability.c:319: Debug: [TPM_RT_KEY]
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008096f0 len=6992 slot=0
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
tpm_cmd_handler.c:4217: Debug: tpm_handle_command(0)
tpm_cmd_handler.c:3514: Debug: [TPM_TAG_RQU_COMMAND]
tpm_cmd_handler.c:3850: Debug: [TPM_ORD_ReadPubek]
tpm_credentials.c:130: Info: TPM_ReadPubek()
tpm_cmd_handler.c:4158: Info: TPM command succeeded
tpm_data.c:209: Debug: size of permanent data: 6963
vtpmblk.c:69: Debug: Begin Write data=0x20008097c0 len=6992 slot=1
ssize=8388608
vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
vtpm_cmd.c:201: Info: Sending encryption key to backend
2015-09-21 16:42 GMT+02:00 Xu, Quan <quan...@intel.com>:
> There are 2 error information:
>
> 1. The following is misleading, but correct. So ignore it.
> ERROR[VTPM]: LoadKey failure: Unrecognized uuid!
> 405ffc60-6b15-48e0-921a-d6645db0be03
> ERROR[VTPM]: Failed to load key
>
> 2. This is maybe the problem:
> ERROR[VTPM]: LoadKey failure: Unrecognized uuid!
> 405ffc60-6b15-48e0-921a-d6645db0be03
> ERROR[VTPM]: Failed to load key
> ERROR in vtpmmgr_LoadHashKey at vtpm_cmd_handler.c:78 code:
> TPM_BAD_PARAMETER.
>
> ....
>
> Share 2 working cfg..
>
> [vtpmmgr]
> kernel="/usr/lib/xen/boot/vtpmmgr-stubdom.gz"
> memory=128
> disk=["file:/var/scale/vdisk/vmgr,hda,w"]
> name="vtpmmgr"
> iomem=["fed40,5"]
>
>
> [Vtpm]
> kernel="/usr/lib/xen/boot/vtpm-stubdom.gz"
> memory=8
> disk=["file:/var/scale/vdisk/vtpm0,hda,w"]
> name="vtpm0"
> vtpm=["backend=vtpmmgr,uuid=6bf5cf32-6c23-4cc7-98e5-398a645a0925"]
>
>
>
> you can also clear TPM 1.2 hardware and reset it.
> also you can upgrade to xen 4.5.0, which is much better than 4.3.0.
>
>
>
>
> Quan
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> From: Zhenyang Feng [mailto:fengzhenyang2...@gmail.com]
> Sent: Sunday, September 20, 2015 7:41 PM
> To: Xu, Quan
> Cc: xen-de...@lists.xenproject.org
> Subject: Re: [Xen-devel] vTPM ownership problem
>
> Hi Quan,
>
> Thank you in advance.
>
> I have set XSM_ENABLE ?=y in xen-4.3.0/Config.mk before install XEN.
>
> I remove the vtpmmgr / vtpm disk and build it again. But the problem still
> exists.
>
> Here is vtpmmgr / vtpm instance log. (Including executing
> tpm_takeownership in domU)
>
>
> vtpmmgr:
> Parsing config from /var/vtpmmgr.cfg
> Daemon running with PID 2922
> Xen Minimal OS!
> start_info: 0xa3000(VA)
> nr_pages: 0x1000
> shared_inf: 0xdb48d000(MA)
> pt_base: 0xa6000(VA)
> nr_pt_frames: 0x5
> mfn_list: 0x9b000(VA)
> mod_start: 0x0(VA)
> mod_len: 0
> flags: 0x0
> cmd_line:
> stack: 0x5a800-0x7a800
> MM: Init
> _text: 0x0(VA)
> _etext: 0x3a284(VA)
> _erodata: 0x46000(VA)
> _edata: 0x48c60(VA)
> stack start: 0x5a800(VA)
> _end: 0x9ae20(VA)
> start_pfn: ae
> max_pfn: 1000
> Mapping memory range 0x400000 - 0x1000000
> setting 0x0-0x46000 readonly
> skipped 0x1000
> MM: Initialise page allocator for b4000(b4000)-1000000(1000000)
> MM: done
> Demand map pfns at 1001000-2001001000.
> Heap resides at 2001002000-4001002000.
> Initialising timer interface
> Initialising console ... done.
> gnttab_table mapped at 0x1001000.
> Initialising scheduler
> Thread "Idle": pointer: 0x2001002050, stack: 0xd0000
> Thread "xenstore": pointer: 0x2001002800, stack: 0xe0000
> xenbus initialised on irq 1 mfn 0x1d0c98
> Thread "shutdown": pointer: 0x2001002fb0, stack: 0xf0000
> Dummy main: start_info=0x7a900
> Thread "main": pointer: 0x2001003760, stack: 0x100000
> "main"
> Shutting down ()
> Shutdown requested: 3
> Thread "shutdown" exited.
> INFO[VTPM]: Starting vTPM manager domain
> INFO[VTPM]: Option: Using tpm_tis driver
> ******************* BLKFRONT for device/vbd/768 **********
>
>
> backend at /local/domain/0/backend/vbd/1/768
> 32768 sectors of 512 bytes
> **************************
> blk_open(device/vbd/768) -> 3
> ============= Init TPM BACK ================
> Thread "tpmback-listener": pointer: 0x20010043f0, stack: 0xf0000
> ============= Init TPM TIS Driver ==============
> IOMEM Machine Base Address: FED40000
> Enabled Localities: 0
> 1.2 TPM (device-id=0x0 vendor-id = 104A rev-id = 4E)
> TPM interface capabilities (0x15):
> Interrupt Level Low
> Locality Change Int Support
> Data Avail Int Support
> tpm_tis_open() -> 4
> INFO[TPM]: TPM_GetCapability
> INFO[VTPM]: Hardware TPM:
> INFO[VTPM]: version: 1 2 8 8
> INFO[VTPM]: specLevel: 2
> INFO[VTPM]: errataRev: 2
> INFO[VTPM]: vendorID: STM
> INFO[VTPM]: vendorSpecificSize: 0
> INFO[VTPM]: vendorSpecific:
> INFO[TPM]: TPM_GetCapability
> INFO[TPM]: TPM_GetCapability
> INFO[VTPM]: Flushing 1 handle(s) of type 2
> INFO[TPM]: TPM_FlushSpecific
> INFO[TPM]: TPM_GetCapability
> INFO[TPM]: TPM_GetCapability
> INFO[TPM]: TPM_GetCapability
> INFO[TPM]: TPM_GetCapability
> INFO[TPM]: TPM_GetRandom
> INFO[TPM]: TPM_GetRandom
> INFO[TPM]: TPM_OIAP
> INFO[TPM]: Auth Session: 0x1639a6 opened by TPM_OIAP.
> INFO[VTPM]: Loading disk image header
> ERROR[VTPM]: Invalid ID string in disk image!
> ERROR[VTPM]: Failed to load manager data!
> INFO[VTPM]: Failed to read manager file. Assuming first time
> initialization.
> INFO[TPM]: TPM_ReadPubek
> INFO[TPM]: TPM_TakeOwnership
> INFO[TPM]: TPM_DisablePubekRead
> INFO[TPM]: TPM_OSAP
> INFO[TPM]: Auth Session: 0xb311d2 opened by TPM_OSAP.
> INFO[TPM]: TPM_CreateWrapKey
> INFO[TPM]: Auth Session: 0xb311d2 closed by TPM
> INFO[TPM]: TPM_LoadKey
> INFO[TPM]: Key Handle: 0x963a83 opened by TPM_LoadKey
> INFO[TPM]: TPM_SaveState
> INFO[VTPM]: Creating new disk image header
> INFO[VTPM]: Saving root storage key..
> INFO[VTPM]: Binding uuid table symmetric key..
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved new manager disk header.
> INFO[VTPM]: Finished initialized new VTPM manager
> INFO[VTPM]: Waiting for commands from vTPM's:
> Tpmback:Info Frontend 2/0 connected
> INFO[VTPM]: Passthrough: TPM_GetRandom
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[VTPM]: Passthrough: TPM_GetRandom
> INFO[VTPM]: Waiting for commands from vTPM's:
> ERROR[VTPM]: LoadKey failure: Unrecognized uuid!
> 405ffc60-6b15-48e0-921a-d6645db0be03
> ERROR[VTPM]: Failed to load key
> ERROR in vtpmmgr_LoadHashKey at vtpm_cmd_handler.c:78 code:
> TPM_BAD_PARAMETER.
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[VTPM]: Registered vtpm 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Generating a new symmetric key
> INFO[VTPM]: Binding encrypted key
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Encrypting the uuid table
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
> INFO[TPM]: TPM_Bind
> INFO[VTPM]: Saved hash and key for vtpm
> 405ffc60-6b15-48e0-921a-d6645db0be03
> INFO[VTPM]: Waiting for commands from vTPM's:
>
>
>
> vtpm:
> Daemon running with PID 3648
> Xen Minimal OS!
> start_info: 0xf2000(VA)
> nr_pages: 0x800
> shared_inf: 0xdb48b000(MA)
> pt_base: 0xf5000(VA)
> nr_pt_frames: 0x5
> mfn_list: 0xee000(VA)
> mod_start: 0x0(VA)
> mod_len: 0
> flags: 0x0
> cmd_line:
> stack: 0xad220-0xcd220
> MM: Init
> _text: 0x0(VA)
> _etext: 0x7f974(VA)
> _erodata: 0x95000(VA)
> _edata: 0x97aa0(VA)
> stack start: 0xad220(VA)
> _end: 0xed840(VA)
> start_pfn: fd
> max_pfn: 800
> Mapping memory range 0x400000 - 0x800000
> setting 0x0-0x95000 readonly
> skipped 0x1000
> MM: Initialise page allocator for ff000(ff000)-800000(800000)
> MM: done
> Demand map pfns at 801000-2000801000.
> Heap resides at 2000802000-4000802000.
> Initialising timer interface
> Initialising console ... done.
> gnttab_table mapped at 0x801000.
> Initialising scheduler
> Thread "Idle": pointer: 0x2000802050, stack: 0x110000
> Thread "xenstore": pointer: 0x2000802800, stack: 0x120000
> xenbus initialised on irq 1 mfn 0x1f7b8c
> Thread "shutdown": pointer: 0x2000802fb0, stack: 0x130000
> Dummy main: start_info=0xcd320
> Thread "main": pointer: 0x2000803760, stack: 0x140000
> "main"
> Shutting down ()
> Shutdown requested: 3
> Thread "shutdown" exited.
> vtpm.c:425: Info: starting TPM Emulator (1.2.0.7-475)
> vtpm.c:357: Info: Startup mode is `clear'
> vtpm.c:387: Info: All PCRs initialized to default values
> vtpm.c:391: Info: TPM Maintenance Commands disabled
> vtpm.c:401: Info: Log level set to (null)
> ============= Init TPM BACK ================
> Thread "tpmback-listener": pointer: 0x2000802fb0, stack: 0x130000
> ============= Init TPM Front ================
> Tpmfront:Info Waiting for backend connection..
> Tpmfront:Info Backend Connected
> Tpmfront:Info Initialization Completed successfully
> vtpmblk.c:34: Info: Initializing persistent NVM storage
>
> ******************* BLKFRONT for device/vbd/768 **********
>
>
> backend at /local/domain/0/backend/vbd/2/768
> 16384 sectors of 512 bytes
> **************************
> blk_open(device/vbd/768) -> 3
> vtpm.c:175: Info: VTPM Initializing
>
> tpm_cmd_handler.c:4113: Debug: tpm_emulator_init(1, 0x00000007)
> vtpm_cmd.c:155: Info: Requesting Encryption key from backend
> vtpm_cmd.c:164: Error: VTPM_LoadHashKey() failed with error code (3)
> vtpm_cmd.c:175: Error: VTPM_LoadHashKey failed
> tpm_data.c:120: Info: initializing TPM data to default values
> tpm_startup.c:29: Info: TPM_Init()
> tpm_testing.c:243: Info: TPM_SelfTestFull()
> tpm_testing.c:39: Debug: tpm_test_prng()
> tpm_testing.c:69: Debug: Monobit: 9994
> tpm_testing.c:70: Debug: Poker: 19.3
> tpm_testing.c:71: Debug: run_1: 2590, 2574
> tpm_testing.c:72: Debug: run_2: 1227, 1206
> tpm_testing.c:73: Debug: run_3: 599, 629
> tpm_testing.c:74: Debug: run_4: 307, 339
> tpm_testing.c:75: Debug: run_5: 167, 154
> tpm_testing.c:76: Debug: run_6+: 157, 146
> tpm_testing.c:77: Debug: run_34: 0
> tpm_testing.c:111: Debug: tpm_test_sha1()
> tpm_testing.c:157: Debug: tpm_test_hmac()
> tpm_testing.c:184: Debug: tpm_test_rsa_EK()
> tpm_testing.c:186: Debug: tpm_rsa_generate_key()
> tpm_testing.c:191: Debug: testing endorsement key
> tpm_testing.c:197: Debug: tpm_rsa_sign(RSA_SSA_PKCS1_SHA1)
> tpm_testing.c:200: Debug: tpm_rsa_verify(RSA_SSA_PKCS1_SHA1)
> tpm_testing.c:203: Debug: tpm_rsa_sign(RSA_SSA_PKCS1_DER)
> tpm_testing.c:206: Debug: tpm_rsa_verify(RSA_SSA_PKCS1_DER)
> tpm_testing.c:210: Debug: tpm_rsa_encrypt(RSA_ES_PKCSV15)
> tpm_testing.c:214: Debug: tpm_rsa_decrypt(RSA_ES_PKCSV15)
> tpm_testing.c:218: Debug: verify plain text
> tpm_testing.c:221: Debug: tpm_rsa_encrypt(RSA_ES_OAEP_SHA1)
> tpm_testing.c:225: Debug: tpm_rsa_decrypt(RSA_ES_OAEP_SHA1)
> tpm_testing.c:229: Debug: verify plain text
> tpm_testing.c:261: Info: Self-Test succeeded
> tpm_startup.c:43: Info: TPM_Startup(1)
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:148: Debug: [TPM_CAP_PROP_TIS_TIMEOUT]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=0
> ssize=4194304
> Tpmback:Info Frontend 3/0 connected
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:199: Debug: [TPM_CAP_PROP_DURATION]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3816: Debug: [TPM_ORD_PCRRead]
> tpm_integrity.c:58: Info: TPM_PCRRead()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3811: Debug: [TPM_ORD_Extend]
> tpm_integrity.c:39: Info: TPM_Extend()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:778: Debug: [TPM_CAP_VERSION_VAL]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:701: Debug: [TPM_CAP_ORD]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:701: Debug: [TPM_CAP_ORD]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:74: Debug: [TPM_CAP_PROP_PCR]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:78: Debug: [TPM_CAP_PROP_DIR]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:86: Debug: [TPM_CAP_PROP_KEYS]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:82: Debug: [TPM_CAP_PROP_MANUFACTURER]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:717: Debug: [TPM_CAP_PROPERTY]
> tpm_capability.c:114: Debug: [TPM_CAP_PROP_MAX_AUTHSESS]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808ef0 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3566: Debug: [TPM_ORD_GetCapability]
> tpm_capability.c:697: Info: TPM_GetCapability()
> tpm_capability.c:725: Debug: [TPM_CAP_KEY_HANDLE]
> tpm_capability.c:319: Debug: [TPM_RT_KEY]
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000808f60 len=6992 slot=0
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
> tpm_cmd_handler.c:4143: Debug: tpm_handle_command(0)
> tpm_cmd_handler.c:3450: Debug: [TPM_TAG_RQU_COMMAND]
> tpm_cmd_handler.c:3786: Debug: [TPM_ORD_ReadPubek]
> tpm_credentials.c:130: Info: TPM_ReadPubek()
> tpm_cmd_handler.c:4084: Info: TPM command succeeded
> tpm_data.c:206: Debug: size of permanent data: 6963
> vtpmblk.c:69: Debug: Begin Write data=0x2000809030 len=6992 slot=1
> ssize=4194304
> vtpmblk.c:88: Info: Wrote 6992 bytes to NVM persistent storage
> vtpm_cmd.c:201: Info: Sending encryption key to backend
>
> Best,
> DearFuture
>
> 2015-09-16 8:15 GMT+02:00 Xu, Quan <quan...@intel.com>:
> 1. For xen 4.3.0, you’d better enable XSM security module.
> 2. share your vtpmmgr / vtpm instance log.
> 3. Clear vtpm / vtpmmgr disk, do it again.
>
>
> Quan
>
>
>
> From: xen-devel-boun...@lists.xen.org [mailto:
> xen-devel-boun...@lists.xen.org] On Behalf Of Zhenyang Feng
> Sent: Wednesday, September 09, 2015 4:40 AM
> To: xen-de...@lists.xenproject.org
> Subject: [Xen-devel] vTPM ownership problem
>
> Hello everyone, I need to use vTPM to finish a project but I encounter the
> same problem as
> http://lists.xenproject.org/archives/html/xen-devel/2015-06/msg03930.html
>
> I followed the steps explained in
> https://mhsamsal.wordpress.com/2013/12/05/configuring-virtual-tpm-vtpm-for-xen-4-3-guest-virtual-machines/
> .
>
> I'm running Ubuntu 14.04 as Dom0 on Dell. I compiled Xen 4.3.0 from
> source. After creating vtpmmgr and vtpm stubdoms, and DomU, I can invoke
> tpm_version as well as cat /sys/class/misc/tpm0/device/pcrs from DomU:
>
> However, I cannot take ownership of vTPM and thus I fail to execute the
> commands required ownership of vTPM. When I invoke takeownership(I set SRK
> password to null) I get the following error:
>
>
> root@tpm-guest:~# tpm_takeownership
> Enter owner password:
> Confirm password:
> Enter SRK password:
> Confirm password:
> Tspi_TPM_TakeOwnership failed: 0x00002004 - layer=tcs, code=0004 (4),
> Internal software error
>
>
> root@tpm-guest:~# tpm_takeownership -z -y -l debug
> Tspi_Context_Create success
> Tspi_Context_Connect success
> Tspi_Context_GetTpmObject success
> Tspi_GetPolicyObject success
> Tspi_Policy_SetSecret success
> Tspi_Context_CreateObject success
> Tspi_GetPolicyObject success
> Tspi_Policy_SetSecret success
> Tspi_TPM_TakeOwnership failed: 0x00002004 - layer=tcs, code=0004 (4),
> Internal software error
> Tspi_Context_CloseObject success
> Tspi_Context_FreeMemory success
> Tspi_Context_Close success
>
> I have just upgraded to Ubuntu 15.04 as the reply said but get the same
> error again. Could you help me handle it? Thank you very much.
>
> Best,
> DearFuture
>
>
>
>
_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
http://lists.xen.org/xen-devel
