[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Xen-devel] vTPM ownership problem



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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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.xu@xxxxxxxxx>:
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:fengzhenyang2014@xxxxxxxxx]
Sent: Sunday, September 20, 2015 7:41 PM
To: Xu, Quan
Cc: xen-devel@xxxxxxxxxxxxxxxxxxxx
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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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="" 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.xu@xxxxxxxxx>:
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-bounces@xxxxxxxxxxxxx [mailto:xen-devel-bounces@xxxxxxxxxxxxx] On Behalf Of Zhenyang Feng
Sent: Wednesday, September 09, 2015 4:40 AM
To: xen-devel@xxxxxxxxxxxxxxxxxxxx
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@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel

 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.