chore(cli/wizard): add diagnostic logs around TOTP vault push

Trace the full CreateItem path (vault state pre/post Unlock, AddItems,
Commit, UpdateVault) and add a Signup round-trip that refetches the
main vault, lists its items, and compares server-recorded
account.mainVault.id and accessor ids against the vault we just wrote
to. Helps localize whether a missing TOTP on the web client is caused
by a failed push, server-side persistence drift, or a vault id /
accessor mismatch.

Made-with: Cursor
This commit is contained in:
Peng Peng 2026-04-21 19:30:10 +08:00
parent c3e2268c78
commit fe9b093582
2 changed files with 105 additions and 0 deletions

View file

@ -133,6 +133,10 @@ func (a *App) Signup(params SignupParams) (*CreateAccountResponse, error) {
// 5. Inject MFA TOTP item into the freshly synchronized main vault
// (ref: apps/packages/sdk/src/core/app.ts:1003-1038).
if mv := a.MainVault(); mv != nil && response.MFA != "" {
log.Printf("Signup: TOTP injection target mv id=%s revision=%s accessors=%d encryptedData=%d aesKey?=%t items?=%t itemCount=%d",
mv.ID, mv.Revision, len(mv.Accessors), len(mv.EncryptedData),
mv.aesKey != nil, mv.items != nil, vaultItemCount(mv))
tpl := GetAuthenticatorTemplate()
if tpl != nil && len(tpl.Fields) > 0 {
tpl.Fields[0].Value = response.MFA
@ -145,8 +149,63 @@ func (a *App) Signup(params SignupParams) (*CreateAccountResponse, error) {
Type: VaultTypeTerminusTotp,
}); err != nil {
log.Printf("Warning: failed to write TOTP item to main vault: %v", err)
log.Printf("CRITICAL: TOTP item not stored in vault, web second-factor will fail: %v", err)
} else {
log.Printf("Main vault updated with TOTP item")
// Round-trip verification: refetch the vault from server,
// unlock with the same account, and list the items the
// server now persists. Diagnostic-only — useful for
// distinguishing "push succeeded" from "push succeeded
// but server did not actually persist TOTP".
if unlocked := a.State.Unlocked(); unlocked != nil {
verify, gerr := a.API.GetVault(mv.ID)
if gerr != nil {
log.Printf("verify: GetVault after TOTP push failed: %v", gerr)
} else {
if uerr := verify.Unlock(unlocked); uerr != nil {
log.Printf("verify: Unlock of refetched vault failed: %v", uerr)
}
count := vaultItemCount(verify)
log.Printf("verify: server vault id=%s revision=%s items=%d accessors=%d encryptedData=%d",
verify.ID, verify.Revision, count,
len(verify.Accessors), len(verify.EncryptedData))
if verify.items != nil {
for _, it := range verify.items.Items {
firstFieldType := ""
if len(it.Fields) > 0 {
firstFieldType = string(it.Fields[0].Type)
}
log.Printf("verify item: id=%s type=%d name=%s fields=%d firstFieldType=%s",
it.ID, it.Type, it.Name, len(it.Fields), firstFieldType)
}
}
// Vault id alignment: compare the vault id we just
// wrote into with the one the server records as
// account.mainVault.id. If they diverge, the web
// client (which reads account.mainVault.id from
// server) will fetch a different vault and never
// see the TOTP item.
srvAcc, aerr := a.API.GetAccount()
if aerr != nil {
log.Printf("post-signup: GetAccount failed: %v", aerr)
} else if srvAcc == nil {
log.Printf("post-signup: GetAccount returned nil account")
} else {
match := srvAcc.MainVault.ID == mv.ID
log.Printf("post-signup: account.id=%s account.did=%s account.mainVault.id=%s vs CLI mv.id=%s match=%t",
srvAcc.ID, srvAcc.DID, srvAcc.MainVault.ID, mv.ID, match)
for i, ac := range verify.Accessors {
accMatch := ac.ID == srvAcc.ID
log.Printf("post-signup: verify.accessors[%d].id=%s vs account.id=%s match=%t",
i, ac.ID, srvAcc.ID, accMatch)
}
}
}
} else {
log.Printf("verify: skipped (no unlocked account in state)")
}
}
}
} else if response.MFA != "" {

View file

@ -163,20 +163,48 @@ func (a *App) CreateItem(params CreateItemParams) (*VaultItem, error) {
}
vault := params.Vault
log.Printf("CreateItem: enter id=%s revision=%s accessors=%d encryptedData=%d aesKey?=%t items?=%t itemCount=%d hasChanges=%t",
vault.ID, vault.Revision, len(vault.Accessors), len(vault.EncryptedData),
vault.aesKey != nil, vault.items != nil, vaultItemCount(vault), vaultHasChanges(vault))
if vault.aesKey == nil {
log.Printf("CreateItem: vault aesKey nil, calling Unlock to bootstrap")
if err := vault.Unlock(unlocked); err != nil {
return nil, fmt.Errorf("unlock vault: %w", err)
}
log.Printf("CreateItem: post-Unlock accessors=%d encryptedData=%d aesKey?=%t",
len(vault.Accessors), len(vault.EncryptedData), vault.aesKey != nil)
}
vault.AddItems(item)
{
fieldType := ""
fieldValueLen := 0
if len(item.Fields) > 0 {
fieldType = string(item.Fields[0].Type)
fieldValueLen = len(item.Fields[0].Value)
}
log.Printf("CreateItem: post-AddItems itemCount=%d added id=%s type=%d fields=%d firstFieldType=%s firstFieldValueLen=%d",
vaultItemCount(vault), item.ID, item.Type, len(item.Fields), fieldType, fieldValueLen)
}
if err := vault.Commit(); err != nil {
return nil, fmt.Errorf("commit vault: %w", err)
}
log.Printf("CreateItem: post-Commit encryptedData=%d iv?=%t aad?=%t",
len(vault.EncryptedData),
vault.EncryptionParams.IV != "", vault.EncryptionParams.AdditionalData != "")
log.Printf("CreateItem: pre-UpdateVault id=%s revision=%s encryptedData=%d accessors=%d",
vault.ID, vault.Revision, len(vault.EncryptedData), len(vault.Accessors))
pushed, err := a.API.UpdateVault(*vault)
if err != nil {
log.Printf("CreateItem: API.UpdateVault failed: %+v", err)
return nil, fmt.Errorf("updateVault: %w", err)
}
log.Printf("CreateItem: post-UpdateVault id=%s revision=%s encryptedData=%d accessors=%d",
pushed.ID, pushed.Revision, len(pushed.EncryptedData), len(pushed.Accessors))
pushed.aesKey = vault.aesKey
pushed.items = vault.items
if err := pushed.Unlock(unlocked); err != nil {
@ -201,6 +229,24 @@ type CreateItemParams struct {
Type VaultType
}
// vaultItemCount returns the number of items currently held in the
// vault's in-memory collection (0 if not yet unlocked).
func vaultItemCount(v *Vault) int {
if v == nil || v.items == nil {
return 0
}
return len(v.items.Items)
}
// vaultHasChanges reports whether the vault's in-memory items collection
// has any pending local changes.
func vaultHasChanges(v *Vault) bool {
if v == nil || v.items == nil {
return false
}
return v.items.HasChanges()
}
// MainVault returns the (possibly nil) Vault stored locally that
// corresponds to account.mainVault.id.
func (a *App) MainVault() *Vault {