Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

failed to update entity in MemDB #13158

Closed
rrijkse opened this issue Nov 16, 2021 · 1 comment · Fixed by #13169
Closed

failed to update entity in MemDB #13158

rrijkse opened this issue Nov 16, 2021 · 1 comment · Fixed by #13169
Labels
bug Used to indicate a potential bug storage/dynamodb

Comments

@rrijkse
Copy link

rrijkse commented Nov 16, 2021 •
edited

Describe the bug
When using version 1.9.0-RC1 (upgrade from 1.8.5) the DynamoDB based vault instance is no longer able to unseal properly the error message from the logs is:

[ERROR] core: post-unseal setup failed: error="failed to update entity in MemDB: failed to update alias into memdb: missing value for index 'local_bucket_key'"

To Reproduce

  • Upgrade vault version to 1.9.0-rc1 and with autounseal the error occurs on startup.

Expected behavior
Startup like normal with an unsealed vault.

Environment:

  • Vault Server Version (retrieve with vault status): 1.9.0-RC1
  • Vault CLI Version (retrieve with vault version): N/A
  • Server Operating System/Architecture: AWS Linux 2

Vault server configuration file(s):

cluster_name = "main"
max_lease_ttl = "768h"
default_lease_ttl = "768h"

disable_clustering = "False"
cluster_addr = "https://INSTANCE_IP:8201"
api_addr = "https://vault.HOSTNAME"

plugin_directory = "/usr/local/lib/vault/plugins"

ui = true

listener "tcp" {
  address = "0.0.0.0:8200"
  cluster_address = "INSTANCE_IP:8201"

  tls_cert_file = "/etc/vault/tls/server.crt"
  tls_key_file = "/etc/vault/tls/server.key"
  tls_min_version  = "tls12"
  tls_cipher_suites = "TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,TLS_RSA_WITH_AES_128_GCM_SHA256,TLS_RSA_WITH_AES_256_GCM_SHA384,TLS_RSA_WITH_AES_128_CBC_SHA,TLS_RSA_WITH_AES_256_CBC_SHA"
  tls_prefer_server_cipher_suites = "True"

  tls_disable = "false"

  proxy_protocol_behavior = "allow_authorized"
  proxy_protocol_authorized_addrs = "CIDR_RANGE/22"
  }

backend "dynamodb" {
    table =          "DB_NAME"
    ha_enabled =     "True"
    read_capacity =  "10"
    write_capacity = "15"
}

seal "awskms" {
  kms_key_id = "REDACTED"
}

service_registration "consul" {
  address      = "127.0.0.1:8500"
}

log_level = "Debug"

Additional Context

Click to expand logs! 
Nov 16 13:44:05 ip-172-16-14-194 vault: ==> Vault server configuration:
Nov 16 13:44:05 ip-172-16-14-194 vault: Api Address: https://vault.sandbox.homexlabs.com
Nov 16 13:44:05 ip-172-16-14-194 vault: Cgo: disabled
Nov 16 13:44:05 ip-172-16-14-194 vault: Cluster Address: https://172.16.14.194:8201
Nov 16 13:44:05 ip-172-16-14-194 vault: Go Version: go1.17.2
Nov 16 13:44:05 ip-172-16-14-194 vault: Listener 1: tcp (addr: "[::]:8220", cluster address: "[::]:8221", max_request_duration: "1m30s", max_request_size: "33554432", tls: "enabled")
Nov 16 13:44:05 ip-172-16-14-194 vault: Listener 2: tcp (addr: "0.0.0.0:8200", cluster address: "172.16.14.194:8201", max_request_duration: "1m30s", max_request_size: "33554432", tls: "enabled")
Nov 16 13:44:05 ip-172-16-14-194 vault: Log Level: debug
Nov 16 13:44:05 ip-172-16-14-194 vault: Mlock: supported: true, enabled: true
Nov 16 13:44:05 ip-172-16-14-194 vault: Recovery Mode: false
Nov 16 13:44:05 ip-172-16-14-194 vault: Storage: dynamodb (HA available)
Nov 16 13:44:05 ip-172-16-14-194 vault: Version: Vault v1.9.0-rc1
Nov 16 13:44:05 ip-172-16-14-194 vault: ==> Vault server started! Log data will stream in below:
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.495Z [INFO]  proxy environment: http_proxy="\"\"" https_proxy="\"\"" no_proxy="\"\""
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.584Z [DEBUG] service_registration.consul: config disable_registration set: disable_registration=false
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.584Z [DEBUG] service_registration.consul: config service set: service=vault
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.584Z [DEBUG] service_registration.consul: config service_tags set: service_tags="\"\""
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.584Z [DEBUG] service_registration.consul: config service_address set: service_address="\"\""
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.584Z [DEBUG] service_registration.consul: config address set: address=127.0.0.1:8500
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.628Z [DEBUG] core: set config: sanitized config="{\"api_addr\":\"https://vault.sandbox.homexlabs.com\",\"cache_size\":0,\"cluster_addr\":\"https://172.16.14.194:8201\",\"cluster_cipher_suites\":\"\",\"cluster_name\":\"main\",\"default_lease_ttl\":2764800000000000,\"default_max_request_duration\":0,\"disable_cache\":false,\"disable_clustering\":false,\"disable_indexing\":false,\"disable_mlock\":false,\"disable_performance_standby\":false,\"disable_printable_check\":false,\"disable_sealwrap\":false,\"disable_sentinel_trace\":false,\"enable_response_header_hostname\":false,\"enable_response_header_raft_node_id\":false,\"enable_ui\":true,\"listeners\":[{\"config\":{\"address\":\"[::]:8220\",\"proxy_protocol_authorized_addrs\":\"172.16.12.0/22\",\"proxy_protocol_behavior\":\"allow_authorized\",\"telemetry\":[{\"unauthenticated_metrics_access\":true}],\"tls_cert_file\":\"/etc/vault/tls/server.crt\",\"tls_cipher_suites\":\"TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,TLS_RSA_WITH_AES_128_GCM_SHA256,TLS_RSA_WITH_AES_256_GCM_SHA384,TLS_RSA_WITH_AES_128_CBC_SHA,TLS_RSA_WITH_AES_256_CBC_SHA\",\"tls_disable\":\"false\",\"tls_key_file\":\"/etc/vault/tls/server.key\",\"tls_min_version\":\"tls12\",\"tls_prefer_server_cipher_suites\":\"True\"},\"type\":\"tcp\"},{\"config\":{\"address\":\"0.0.0.0:8200\",\"cluster_address\":\"172.16.14.194:8201\",\"proxy_protocol_authorized_addrs\":\"172.16.12.0/22\",\"proxy_protocol_behavior\":\"allow_authorized\",\"tls_cert_file\":\"/etc/vault/tls/server.crt\",\"tls_cipher_suites\":\"TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,TLS_RSA_WITH_AES_128_GCM_SHA256,TLS_RSA_WITH_AES_256_GCM_SHA384,TLS_RSA_WITH_AES_128_CBC_SHA,TLS_RSA_WITH_AES_256_CBC_SHA\",\"tls_disable\":\"false\",\"tls_key_file\":\"/etc/vault/tls/server.key\",\"tls_min_version\":\"tls12\",\"tls_prefer_server_cipher_suites\":\"True\"},\"type\":\"tcp\"}],\"log_format\":\"unspecified\",\"log_level\":\"Debug\",\"max_lease_ttl\":2764800000000000,\"pid_file\":\"\",\"plugin_directory\":\"/usr/local/lib/vault/plugins\",\"raw_storage_endpoint\":false,\"seals\":[{\"disabled\":false,\"type\":\"awskms\"}],\"service_registration\":{\"type\":\"consul\"},\"storage\":{\"cluster_addr\":\"https://172.16.14.194:8201\",\"disable_clustering\":false,\"redirect_addr\":\"https://vault.sandbox.homexlabs.com\",\"type\":\"dynamodb\"},\"telemetry\":{\"add_lease_metrics_namespace_labels\":false,\"circonus_api_app\":\"\",\"circonus_api_token\":\"\",\"circonus_api_url\":\"\",\"circonus_broker_id\":\"\",\"circonus_broker_select_tag\":\"\",\"circonus_check_display_name\":\"\",\"circonus_check_force_metric_activation\":\"\",\"circonus_check_id\":\"\",\"circonus_check_instance_id\":\"\",\"circonus_check_search_tag\":\"\",\"circonus_check_tags\":\"\",\"circonus_submission_interval\":\"\",\"circonus_submission_url\":\"\",\"disable_hostname\":true,\"dogstatsd_addr\":\"\",\"dogstatsd_tags\":null,\"lease_metrics_epsilon\":3600000000000,\"maximum_gauge_cardinality\":500,\"metrics_prefix\":\"\",\"num_lease_metrics_buckets\":168,\"prometheus_retention_time\":2678400000000000,\"stackdriver_debug_logs\":false,\"stackdriver_location\":\"\",\"stackdriver_namespace\":\"\",\"stackdriver_project_id\":\"\",\"statsd_address\":\"\",\"statsite_address\":\"\",\"usage_gauge_period\":600000000000}}"
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.628Z [DEBUG] storage.cache: creating LRU cache: size=0
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.671Z [INFO]  core: Initializing VersionTimestamps for core
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.674Z [DEBUG] cluster listener addresses synthesized: cluster_addresses=[[::]:8221, 172.16.14.194:8201]
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.674Z [DEBUG] would have sent systemd notification (systemd not present): notification=READY=1
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.674Z [INFO]  core: stored unseal keys supported, attempting fetch
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.678Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [DEBUG] core: starting cluster listeners
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [INFO]  core.cluster-listener.tcp: starting listener: listener_address=[::]:8221
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [INFO]  core.cluster-listener.tcp: starting listener: listener_address=172.16.14.194:8201
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [INFO]  core.cluster-listener: serving cluster requests: cluster_listen_address=[::]:8221
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [INFO]  core.cluster-listener: serving cluster requests: cluster_listen_address=172.16.14.194:8201
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [INFO]  core: vault is unsealed
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [WARN]  service_registration.consul: concurrent initalize state change notify dropped
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.748Z [INFO]  core: unsealed with stored key
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.749Z [INFO]  core: entering standby mode
Nov 16 13:44:05 ip-172-16-14-194 vault: 2021-11-16T13:44:05.751Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.680Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.752Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.755Z [INFO]  core: acquired lock, enabling active operation
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.786Z [DEBUG] core: generating cluster private key
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.789Z [DEBUG] core: generating local cluster certificate
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.805Z [INFO]  core: post-unseal setup starting
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.809Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.809Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.809Z [DEBUG] core: persisting feature flags
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.818Z [INFO]  core: loaded wrapping token key
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.822Z [INFO]  core: upgrading plugin information: plugins=[]
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.822Z [INFO]  core: successfully setup plugin catalog: plugin-directory=/usr/local/lib/vault/plugins
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.830Z [INFO]  core: successfully mounted backend: type=system path=sys/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.830Z [INFO]  core: successfully mounted backend: type=identity path=identity/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.834Z [INFO]  core: successfully mounted backend: type=kv path=secret/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.840Z [INFO]  core: successfully mounted backend: type=aws path=aws/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.841Z [INFO]  core: successfully mounted backend: type=database path=database/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.841Z [INFO]  core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.841Z [INFO]  secrets.database.database_404a9f5e: initializing database rotation queue
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.849Z [INFO]  core: successfully mounted backend: type=pki path=pki/server/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.849Z [INFO]  core: successfully mounted backend: type=pki path=pki/root/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.849Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/root/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.850Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-1/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.850Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-2/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.851Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/se-us-east-1/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.885Z [INFO]  core: successfully enabled credential backend: type=token path=token/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.892Z [INFO]  core: successfully enabled credential backend: type=approle path=approle/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.900Z [INFO]  core: successfully enabled credential backend: type=oidc path=oidc/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.904Z [INFO]  core: successfully enabled credential backend: type=aws path=aws/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.911Z [INFO]  core: successfully enabled credential backend: type=kubernetes path=k8s-devops-sbx/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.921Z [INFO]  rollback: starting rollback manager
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.922Z [INFO]  core: restoring leases
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.922Z [DEBUG] expiration: collecting leases
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.930Z [DEBUG] audit: adding reload function: path=file/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.930Z [DEBUG] audit: file backend options: path=file/ file_path=/var/log/vault/audit.log
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.930Z [DEBUG] identity: loading entities
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.937Z [DEBUG] identity: entities collected: num_existing=44
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.938Z [DEBUG] identity: entities loading: progress=0
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.952Z [INFO]  core: pre-seal teardown starting
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.954Z [DEBUG] audit: removing reload function: path=file/
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.954Z [DEBUG] expiration: stop triggered
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.954Z [DEBUG] expiration: finished stopping
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.954Z [INFO]  rollback: stopping rollback manager
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.953Z [WARN]  expiration: context canceled while restoring leases, stopping lease loading
Nov 16 13:44:06 ip-172-16-14-194 vault: 2021-11-16T13:44:06.958Z [INFO]  secrets.database.database_404a9f5e: queue initialization canceled
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.000Z [INFO]  core: pre-seal teardown complete
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.001Z [ERROR] core: post-unseal setup failed: error="failed to update entity in MemDB: failed to update alias into memdb: missing value for index 'local_bucket_key'"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.009Z [DEBUG] core: parsing information for new active node: active_cluster_addr=https://172.16.14.194:8201 active_redirect_addr=https://vault.sandbox.homexlabs.com
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.009Z [DEBUG] core: refreshing forwarding connection
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.009Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.009Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.009Z [DEBUG] core: done refreshing forwarding connection
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.009Z [DEBUG] core.cluster-listener: creating rpc dialer: address=172.16.14.194:8201 alpn=req_fw_sb-act_v1 host=fw-d2fec914-b351-ccd0-b40f-2454d0a9075f
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.010Z [WARN]  core.cluster-listener: no TLS config found for ALPN: ALPN=["req_fw_sb-act_v1"]
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.010Z [DEBUG] core.cluster-listener: error handshaking cluster connection: error="unsupported protocol"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.010Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.010Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.011Z [DEBUG] core: forwarding: error sending echo request to active node: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.681Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:07 ip-172-16-14-194 vault: 2021-11-16T13:44:07.754Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:08 ip-172-16-14-194 vault: 2021-11-16T13:44:08.681Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:08 ip-172-16-14-194 vault: 2021-11-16T13:44:08.754Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.014Z [INFO]  core: acquired lock, enabling active operation
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.043Z [DEBUG] core: generating cluster private key
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.046Z [DEBUG] core: generating local cluster certificate
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.061Z [INFO]  core: post-unseal setup starting
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.064Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.064Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.064Z [DEBUG] core: persisting feature flags
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.064Z [DEBUG] core: forwarding: stopping heartbeating
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.073Z [INFO]  core: loaded wrapping token key
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.077Z [INFO]  core: upgrading plugin information: plugins=[]
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.077Z [INFO]  core: successfully setup plugin catalog: plugin-directory=/usr/local/lib/vault/plugins
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.084Z [INFO]  core: successfully mounted backend: type=system path=sys/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.086Z [INFO]  core: successfully mounted backend: type=identity path=identity/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.100Z [INFO]  core: successfully mounted backend: type=kv path=secret/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.106Z [INFO]  core: successfully mounted backend: type=aws path=aws/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.106Z [INFO]  core: successfully mounted backend: type=database path=database/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.106Z [INFO]  core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.107Z [INFO]  secrets.database.database_404a9f5e: initializing database rotation queue
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.114Z [INFO]  core: successfully mounted backend: type=pki path=pki/server/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.115Z [INFO]  core: successfully mounted backend: type=pki path=pki/root/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.115Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/root/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.115Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-1/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.116Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-2/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.116Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/se-us-east-1/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.143Z [INFO]  core: successfully enabled credential backend: type=token path=token/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.150Z [INFO]  core: successfully enabled credential backend: type=approle path=approle/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.156Z [INFO]  core: successfully enabled credential backend: type=oidc path=oidc/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.159Z [INFO]  core: successfully enabled credential backend: type=aws path=aws/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.166Z [INFO]  core: successfully enabled credential backend: type=kubernetes path=k8s-devops-sbx/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.179Z [INFO]  rollback: starting rollback manager
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.179Z [INFO]  core: restoring leases
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.179Z [DEBUG] expiration: collecting leases
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.187Z [DEBUG] audit: adding reload function: path=file/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.187Z [DEBUG] audit: file backend options: path=file/ file_path=/var/log/vault/audit.log
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.187Z [DEBUG] identity: loading entities
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.193Z [DEBUG] identity: entities collected: num_existing=44
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.193Z [DEBUG] identity: entities loading: progress=0
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.202Z [INFO]  core: pre-seal teardown starting
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.203Z [DEBUG] audit: removing reload function: path=file/
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.203Z [DEBUG] expiration: stop triggered
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.244Z [WARN]  expiration: context canceled while restoring leases, stopping lease loading
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.246Z [DEBUG] expiration: finished stopping
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.246Z [INFO]  rollback: stopping rollback manager
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.253Z [INFO]  core: pre-seal teardown complete
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.253Z [ERROR] core: post-unseal setup failed: error="failed to update entity in MemDB: failed to update alias into memdb: missing value for index 'local_bucket_key'"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.257Z [INFO]  secrets.database.database_404a9f5e: queue initialization canceled
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.261Z [DEBUG] core: parsing information for new active node: active_cluster_addr=https://172.16.14.194:8201 active_redirect_addr=https://vault.sandbox.homexlabs.com
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.261Z [DEBUG] core: refreshing forwarding connection
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.261Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.261Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.261Z [DEBUG] core: done refreshing forwarding connection
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.261Z [DEBUG] core.cluster-listener: creating rpc dialer: address=172.16.14.194:8201 alpn=req_fw_sb-act_v1 host=fw-a7b844a8-c24a-c7a9-0067-13ca6a7ed73c
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.262Z [WARN]  core.cluster-listener: no TLS config found for ALPN: ALPN=["req_fw_sb-act_v1"]
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.262Z [DEBUG] core.cluster-listener: error handshaking cluster connection: error="unsupported protocol"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.262Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.263Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.263Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.263Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.263Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [DEBUG] core: forwarding: error sending echo request to active node: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.264Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.683Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:09 ip-172-16-14-194 vault: 2021-11-16T13:44:09.755Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:10 ip-172-16-14-194 vault: 2021-11-16T13:44:10.685Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:10 ip-172-16-14-194 vault: 2021-11-16T13:44:10.756Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.264Z [INFO]  core: acquired lock, enabling active operation
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.292Z [DEBUG] core: generating cluster private key
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.296Z [DEBUG] core: generating local cluster certificate
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.313Z [INFO]  core: post-unseal setup starting
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.316Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.316Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.316Z [DEBUG] core: persisting feature flags
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.317Z [DEBUG] core: forwarding: stopping heartbeating
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.325Z [INFO]  core: loaded wrapping token key
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.328Z [INFO]  core: upgrading plugin information: plugins=[]
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.328Z [INFO]  core: successfully setup plugin catalog: plugin-directory=/usr/local/lib/vault/plugins
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.336Z [INFO]  core: successfully mounted backend: type=system path=sys/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.337Z [INFO]  core: successfully mounted backend: type=identity path=identity/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.341Z [INFO]  core: successfully mounted backend: type=kv path=secret/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.347Z [INFO]  core: successfully mounted backend: type=aws path=aws/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.347Z [INFO]  core: successfully mounted backend: type=database path=database/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.347Z [INFO]  core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.348Z [INFO]  secrets.database.database_404a9f5e: initializing database rotation queue
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.354Z [INFO]  core: successfully mounted backend: type=pki path=pki/server/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.355Z [INFO]  core: successfully mounted backend: type=pki path=pki/root/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.355Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/root/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.355Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-1/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.355Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-2/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.355Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/se-us-east-1/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.387Z [INFO]  core: successfully enabled credential backend: type=token path=token/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.393Z [INFO]  core: successfully enabled credential backend: type=approle path=approle/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.400Z [INFO]  core: successfully enabled credential backend: type=oidc path=oidc/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.404Z [INFO]  core: successfully enabled credential backend: type=aws path=aws/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.410Z [INFO]  core: successfully enabled credential backend: type=kubernetes path=k8s-devops-sbx/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.422Z [INFO]  core: restoring leases
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.423Z [INFO]  rollback: starting rollback manager
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.423Z [DEBUG] expiration: collecting leases
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.431Z [DEBUG] audit: adding reload function: path=file/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.432Z [DEBUG] audit: file backend options: path=file/ file_path=/var/log/vault/audit.log
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.432Z [DEBUG] identity: loading entities
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.439Z [DEBUG] identity: entities collected: num_existing=44
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.440Z [DEBUG] identity: entities loading: progress=0
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.451Z [INFO]  core: pre-seal teardown starting
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.471Z [DEBUG] audit: removing reload function: path=file/
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.471Z [DEBUG] expiration: stop triggered
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.472Z [DEBUG] expiration: finished stopping
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.472Z [INFO]  rollback: stopping rollback manager
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.471Z [WARN]  expiration: context canceled while restoring leases, stopping lease loading
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.481Z [INFO]  secrets.database.database_404a9f5e: queue initialization canceled
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.492Z [INFO]  core: pre-seal teardown complete
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.492Z [ERROR] core: post-unseal setup failed: error="failed to update entity in MemDB: failed to update alias into memdb: missing value for index 'local_bucket_key'"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.499Z [DEBUG] core: parsing information for new active node: active_cluster_addr=https://172.16.14.194:8201 active_redirect_addr=https://vault.sandbox.homexlabs.com
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.500Z [DEBUG] core: refreshing forwarding connection
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.500Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.500Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.500Z [DEBUG] core: done refreshing forwarding connection
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.500Z [DEBUG] core.cluster-listener: creating rpc dialer: address=172.16.14.194:8201 alpn=req_fw_sb-act_v1 host=fw-1023e63a-e5bb-d79e-2bf4-00a8740b3d3b
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.501Z [WARN]  core.cluster-listener: no TLS config found for ALPN: ALPN=["req_fw_sb-act_v1"]
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.502Z [DEBUG] core.cluster-listener: error handshaking cluster connection: error="unsupported protocol"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [DEBUG] core: forwarding: error sending echo request to active node: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.503Z [ERROR] core: error during forwarded RPC request: error="rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing remote error: tls: internal error\""
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.504Z [ERROR] core: forward request error: error="error during forwarding RPC request"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.686Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:11 ip-172-16-14-194 vault: 2021-11-16T13:44:11.757Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:12 ip-172-16-14-194 vault: 2021-11-16T13:44:12.687Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:12 ip-172-16-14-194 vault: 2021-11-16T13:44:12.758Z [WARN]  service_registration.consul: check unable to talk with Consul backend: error="Put \"http://127.0.0.1:8500/v1/agent/check/pass/vault::443:vault-sealed-check?note=Vault+Unsealed\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.508Z [INFO]  core: acquired lock, enabling active operation
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.544Z [DEBUG] core: generating cluster private key
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.548Z [DEBUG] core: generating local cluster certificate
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.571Z [INFO]  core: post-unseal setup starting
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.574Z [DEBUG] core: clearing forwarding clients
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.574Z [DEBUG] core: done clearing forwarding clients
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.574Z [DEBUG] core: persisting feature flags
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.575Z [DEBUG] core: forwarding: stopping heartbeating
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.584Z [INFO]  core: loaded wrapping token key
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.589Z [INFO]  core: upgrading plugin information: plugins=[]
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.589Z [INFO]  core: successfully setup plugin catalog: plugin-directory=/usr/local/lib/vault/plugins
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.604Z [INFO]  core: successfully mounted backend: type=system path=sys/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.604Z [INFO]  core: successfully mounted backend: type=identity path=identity/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.613Z [INFO]  core: successfully mounted backend: type=kv path=secret/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.621Z [INFO]  core: successfully mounted backend: type=aws path=aws/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.621Z [INFO]  core: successfully mounted backend: type=database path=database/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.621Z [INFO]  core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.621Z [INFO]  secrets.database.database_404a9f5e: initializing database rotation queue
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.629Z [INFO]  core: successfully mounted backend: type=pki path=pki/server/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.629Z [INFO]  core: successfully mounted backend: type=pki path=pki/root/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.630Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/root/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.630Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-1/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.632Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/hx-us-east-2/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.633Z [INFO]  core: successfully mounted backend: type=pki path=pki/consul/sbx/se-us-east-1/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.668Z [INFO]  core: successfully enabled credential backend: type=token path=token/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.675Z [INFO]  core: successfully enabled credential backend: type=approle path=approle/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.684Z [INFO]  core: successfully enabled credential backend: type=oidc path=oidc/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.687Z [INFO]  core: successfully enabled credential backend: type=aws path=aws/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.688Z [WARN]  service_registration.consul: reconcile unable to talk with Consul backend: error="service registration failed: Put \"http://127.0.0.1:8500/v1/agent/service/register\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.694Z [INFO]  core: successfully enabled credential backend: type=kubernetes path=k8s-devops-sbx/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.708Z [INFO]  rollback: starting rollback manager
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.709Z [INFO]  core: restoring leases
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.709Z [DEBUG] expiration: collecting leases
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.716Z [DEBUG] audit: adding reload function: path=file/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.716Z [DEBUG] audit: file backend options: path=file/ file_path=/var/log/vault/audit.log
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.716Z [DEBUG] identity: loading entities
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.724Z [DEBUG] identity: entities collected: num_existing=44
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.725Z [DEBUG] identity: entities loading: progress=0
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.738Z [INFO]  core: pre-seal teardown starting
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.738Z [DEBUG] audit: removing reload function: path=file/
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.739Z [DEBUG] expiration: stop triggered
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.740Z [WARN]  expiration: context canceled while restoring leases, stopping lease loading
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.749Z [DEBUG] expiration: finished stopping
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.750Z [INFO]  rollback: stopping rollback manager
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.750Z [INFO]  core: pre-seal teardown complete
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.750Z [ERROR] core: post-unseal setup failed: error="failed to update entity in MemDB: failed to update alias into memdb: missing value for index 'local_bucket_key'"
Nov 16 13:44:13 ip-172-16-14-194 vault: 2021-11-16T13:44:13.754Z [INFO]  secrets.database.database_404a9f5e: queue initialization canceled
@hsimon-hashicorp
Copy link
Contributor

Thanks for this report! Since it involves an RC, we'll get an engineer to look at this right away. Really appreciate it.

@hsimon-hashicorp hsimon-hashicorp added the bug Used to indicate a potential bug label Nov 16, 2021
@ncabatoff ncabatoff mentioned this issue Nov 16, 2021
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Used to indicate a potential bug storage/dynamodb
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix startup failures when aliases from a pre-1.9 vault version exist hashicorp/vault
2 participants
@rrijkse @hsimon-hashicorp