vtpm_manager can not load NVM

View: New views

1 Messages — Rating Filter: Alert me

vtpm_manager can not load NVM

by Erdem Bayer-2 :: Rate this Message:

Reply to Author | View Threaded | Show Only this Message

Hi

When a domain is started with option vtpm = [ 'instance=1, backend=0' ] vtpm
for the domain always starts with parameter "clear", resulting in all keystore
inaccessable because the previous SRK is lost. I could not find a way to save
the vtpm state in any way. The vtpm_manager output includes these:

TPMD[1]: tpm/tpm_startup.c:45: Info: TPM_Startup(1)
Loading NVM.
Sending LoadNVM command
ERROR[VTPM]: Failed to load NVM
.INFO[VTPM]: [VTPM Listener]: VTPM Listener waiting for messages.
Reading LoadNVM header

when I checked the code and mailing lists, this NVM is actually resides in
dom0 filesystem, namely /var/vtpm/vtpm_dm_%d.data but the vtpm_manager does
not create this when it started, nor it complains.

I am having this issue with xen versions 3.1.3-RELEASE and 3.1-testing, but
did not test with 3.2 branch.

I will also attach the vtpm_manager output.

I appologize for the cross-post.

Thank you.
Erdem Bayer

erdem-d ~ # vtpm_managerd
INFO[VTPM]: Starting VTPM.
INFO[TCS]: Constructing new TCS:
INFO[TCS]: Calling TCS_OpenContext:
INFO[VTSP]: OIAP.
ERROR[VTPM]: Failed to load service data with error = TPM_IOERROR
INFO[VTPM]: Failed to read manager file. Assuming first time initialization.
INFO[VTSP]: Reading Public EK.
INFO[VTSP]: Taking Ownership of TPM.
INFO[VTSP]: OSAP.
INFO[VTSP]: Creating new key of type 20.
INFO[VTSP]: Creating Binding Key...
INFO[VTSP]: OSAP.
INFO[VTSP]: Creating new key of type 20.
INFO[VTSP]: Creating Binding Key...
INFO[VTSP]: Loading Key only into memory.
INFO[VTSP]: Calling TPM_SaveState.
INFO[VTPM]: Finished initialized new VTPM manager (Status = 0).
INFO[VTSP]: Binding 16 bytes of data.
INFO[VTPM]: Saved 256 bytes of E(symkey) + 656 bytes of E(data)
INFO[VTPM]: Saved VTPM Manager state (status = 0, dmis = -1)
INFO[VTSP]: Loading Key into TPM.
INFO[VTPM]: Creating new DMI instance 0 attached.
INFO[TCS]: Calling TCS_OpenContext:
INFO[VTPM]: [Backend Listener]: Backend Listener waiting for messages.
INFO[VTPM]: [VTPM Listener]: VTPM Listener waiting for messages.
INFO[VTPM]: [Hotplug Listener]: Hotplug Listener waiting for messages.
INFO[VTPM]: Creating new DMI instance 1 attached.
INFO[TCS]: Calling TCS_OpenContext:
TPMD[1]: tpmd.c:126: Info: Initializing tpm state: clear, type: pvm, id: 1

TPMD[1]: tpm/tpm_cmd_handler.c:4143: Debug: tpm_emulator_init()
INFO[VTPM]: Launching DMI on PID = 8330
INFO[VTSP]: Binding 16 bytes of data.
INFO[VTPM]: Saved 256 bytes of E(symkey) + 656 bytes of E(data)
INFO[VTPM]: Saved VTPM Manager state (status = 0, dmis = 1)
INFO[VTPM]: [Hotplug Listener]: Hotplug Listener waiting for messages.
TPMD[1]: tpm/tpm_startup.c:30: Info: TPM_Init()
TPMD[1]: tpm/tpm_testing.c:242: Info: TPM_SelfTestFull()
TPMD[1]: tpm/tpm_testing.c:42: Debug: tpm_test_prng()
TPMD[1]: tpm/tpm_testing.c:70: Debug: Monobit: 10022
TPMD[1]: tpm/tpm_testing.c:71: Debug: Poker: 10.0
TPMD[1]: tpm/tpm_testing.c:72: Debug: run_1: 2490, 2523
TPMD[1]: tpm/tpm_testing.c:73: Debug: run_2: 1258, 1197
TPMD[1]: tpm/tpm_testing.c:74: Debug: run_3: 629, 669
TPMD[1]: tpm/tpm_testing.c:75: Debug: run_4: 313, 291
TPMD[1]: tpm/tpm_testing.c:76: Debug: run_5: 151, 164
TPMD[1]: tpm/tpm_testing.c:77: Debug: run_6+: 158, 156
TPMD[1]: tpm/tpm_testing.c:78: Debug: run_34: 0
TPMD[1]: tpm/tpm_testing.c:112: Debug: tpm_test_sha1()
TPMD[1]: tpm/tpm_testing.c:156: Debug: tpm_test_hmac()
TPMD[1]: tpm/tpm_testing.c:183: Debug: tpm_test_rsa_EK()
TPMD[1]: tpm/tpm_testing.c:185: Debug: rsa_generate_key()
TPMD[1]: tpm/tpm_testing.c:190: Debug: testing endorsement key
TPMD[1]: tpm/tpm_testing.c:196: Debug: rsa_sign(RSA_SSA_PKCS1_SHA1)
TPMD[1]: tpm/tpm_testing.c:199: Debug: rsa_verify(RSA_SSA_PKCS1_SHA1)
TPMD[1]: tpm/tpm_testing.c:202: Debug: rsa_sign(RSA_SSA_PKCS1_DER)
TPMD[1]: tpm/tpm_testing.c:205: Debug: rsa_verify(RSA_SSA_PKCS1_DER)
TPMD[1]: tpm/tpm_testing.c:209: Debug: rsa_encrypt(RSA_ES_PKCSV15)
TPMD[1]: tpm/tpm_testing.c:213: Debug: rsa_decrypt(RSA_ES_PKCSV15)
TPMD[1]: tpm/tpm_testing.c:217: Debug: verify plain text
TPMD[1]: tpm/tpm_testing.c:220: Debug: rsa_encrypt(RSA_ES_OAEP_SHA1)
TPMD[1]: tpm/tpm_testing.c:224: Debug: rsa_decrypt(RSA_ES_OAEP_SHA1)
TPMD[1]: tpm/tpm_testing.c:228: Debug: verify plain text
TPMD[1]: tpm/tpm_testing.c:260: Info: Self-Test succeeded
TPMD[1]: tpm/tpm_startup.c:45: Info: TPM_Startup(1)
Loading NVM.
Sending LoadNVM command
ERROR[VTPM]: Failed to load NVM
.INFO[VTPM]: [VTPM Listener]: VTPM Listener waiting for messages.
Reading LoadNVM header
INFO[VTPM]: Closing DMI 1.
INFO[TCS]: Calling TCS_CloseContext.
INFO[VTPM]: Killing dmi on pid 8330.
INFO[VTSP]: Binding 16 bytes of data.
INFO[VTPM]: Saved 256 bytes of E(symkey) + 656 bytes of E(data)
INFO[VTPM]: Saved VTPM Manager state (status = 0, dmis = 1)
INFO[VTPM]: [Hotplug Listener]: Hotplug Listener waiting for messages.
INFO[VTPM]: Re-attaching DMI instance 1.
INFO[TCS]: Calling TCS_OpenContext:
INFO[VTPM]: Launching DMI on PID = 8878
INFO[VTSP]: Binding 16 bytes of data.
TPMD[1]: tpmd.c:126: Info: Initializing tpm state: clear, type: pvm, id: 1

TPMD[1]: tpm/tpm_cmd_handler.c:4143: Debug: tpm_emulator_init()
INFO[VTPM]: Saved 256 bytes of E(symkey) + 656 bytes of E(data)
INFO[VTPM]: Saved VTPM Manager state (status = 0, dmis = 1)
INFO[VTPM]: [Hotplug Listener]: Hotplug Listener waiting for messages.
TPMD[1]: tpm/tpm_startup.c:30: Info: TPM_Init()
TPMD[1]: tpm/tpm_testing.c:242: Info: TPM_SelfTestFull()
TPMD[1]: tpm/tpm_testing.c:42: Debug: tpm_test_prng()
TPMD[1]: tpm/tpm_testing.c:70: Debug: Monobit: 10252
TPMD[1]: tpm/tpm_testing.c:71: Debug: Poker: 24.5
TPMD[1]: tpm/tpm_testing.c:72: Debug: run_1: 2545, 2452
TPMD[1]: tpm/tpm_testing.c:73: Debug: run_2: 1251, 1249
TPMD[1]: tpm/tpm_testing.c:74: Debug: run_3: 636, 628
TPMD[1]: tpm/tpm_testing.c:75: Debug: run_4: 311, 317
TPMD[1]: tpm/tpm_testing.c:76: Debug: run_5: 123, 159
TPMD[1]: tpm/tpm_testing.c:77: Debug: run_6+: 135, 196
TPMD[1]: tpm/tpm_testing.c:78: Debug: run_34: 0
TPMD[1]: tpm/tpm_testing.c:112: Debug: tpm_test_sha1()
TPMD[1]: tpm/tpm_testing.c:156: Debug: tpm_test_hmac()
TPMD[1]: tpm/tpm_testing.c:183: Debug: tpm_test_rsa_EK()
TPMD[1]: tpm/tpm_testing.c:185: Debug: rsa_generate_key()
TPMD[1]: tpm/tpm_testing.c:190: Debug: testing endorsement key
TPMD[1]: tpm/tpm_testing.c:196: Debug: rsa_sign(RSA_SSA_PKCS1_SHA1)
TPMD[1]: tpm/tpm_testing.c:199: Debug: rsa_verify(RSA_SSA_PKCS1_SHA1)
TPMD[1]: tpm/tpm_testing.c:202: Debug: rsa_sign(RSA_SSA_PKCS1_DER)
TPMD[1]: tpm/tpm_testing.c:205: Debug: rsa_verify(RSA_SSA_PKCS1_DER)
TPMD[1]: tpm/tpm_testing.c:209: Debug: rsa_encrypt(RSA_ES_PKCSV15)
TPMD[1]: tpm/tpm_testing.c:213: Debug: rsa_decrypt(RSA_ES_PKCSV15)
TPMD[1]: tpm/tpm_testing.c:217: Debug: verify plain text
TPMD[1]: tpm/tpm_testing.c:220: Debug: rsa_encrypt(RSA_ES_OAEP_SHA1)
TPMD[1]: tpm/tpm_testing.c:224: Debug: rsa_decrypt(RSA_ES_OAEP_SHA1)
TPMD[1]: tpm/tpm_testing.c:228: Debug: verify plain text
TPMD[1]: tpm/tpm_testing.c:260: Info: Self-Test succeeded
TPMD[1]: tpm/tpm_startup.c:45: Info: TPM_Startup(1)
Loading NVM.
Sending LoadNVM command
ERROR[VTPM]: Failed to load NVM
.INFO[VTPM]: [VTPM Listener]: VTPM Listener waiting for messages.
Reading LoadNVM header

_______________________________________________
Xense-devel mailing list
Xense-devel@...
http://lists.xensource.com/xense-devel

signature.asc (196 bytes) Download Attachment