isantisteban
Contributor
Contributor

vcsa 7.0.2 does not allow creating backups, vcha service does not start

In early August, we changed the certificate for machine_ssl to use a hybrid environment at the certificate level. The vcsa backup has operated perfectly until October 9, taking the vcsa backup copies every day, from that day the vcha service does not work and manually starting it reports:

root@vcenter [ ~ ]# service-control --status
Running:
applmgmt lookupsvc lwsmd observability observability-vapi pschealth vlcm vmafdd vmcad vmdird vmonapi vmware-analytics vmware-certificateauthority vmware-certificatemanagement vmware-cis-license vmware-content-library vmware-eam vmware-envoy vmware-hvc vmware-infraprofile vmware-perfcharts vmware-pod vmware-postgres-archiver vmware-rhttpproxy vmware-sca vmware-sps vmware-statsmonitor vmware-stsd vmware-topologysvc vmware-trustmanagement vmware-updatemgr vmware-vapi-endpoint vmware-vdtc vmware-vmon vmware-vpostgres vmware-vpxd vmware-vpxd-svcs vmware-vsan-health vmware-vsm vsphere-ui vstats vtsdb wcp
Stopped:
vmcam vmware-imagebuilder vmware-netdumper vmware-rbd-watchdog vmware-vcha
root@vcenter [ ~ ]# service-control --start vmware-vcha
Operation not cancellable. Please wait for it to finish...
Performing start operation on service vcha...
Error executing start on service vcha. Details {
"detail": [
{
"id": "install.ciscommon.service.failstart",
"translatable": "An error occurred while starting service '%(0)s'",
"args": [
"vcha"
],
"localized": "An error occurred while starting service 'vcha'"
}
],
"componentKey": null,
"problemId": null,
"resolution": null
}
Service-control failed. Error: {
"detail": [
{
"id": "install.ciscommon.service.failstart",
"translatable": "An error occurred while starting service '%(0)s'",
"args": [
"vcha"
],
"localized": "An error occurred while starting service 'vcha'"
}
],
"componentKey": null,
"problemId": null,
"resolution": null
}

But there is no clue that indicates what exactly happens, the service when launching it manually the service log says:

2021-10-12T18:43:57.797+02:00 - time the service was last started, Section for vCenterHA, pid=1727, version=7.0.2, build=18355781, option=Release
2021-10-12T18:43:57.784+02:00 none -[01727] [Originator@6876 sub=Default] 000055c965cba490
2021-10-12T18:43:57.791+02:00 info -[01727] [Originator@6876 sub=Default] Glibc malloc guards disabled.
2021-10-12T18:43:57.791+02:00 info -[01727] [Originator@6876 sub=Default] Initialized SystemFactory
2021-10-12T18:43:57.797+02:00 warning vcha[01727] [Originator@6876 sub=Default] Unrecognized log/level '' using 'info'
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=Default] Logging uses fast path: true
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=Default] The bora/lib logs WILL be handled by VmaCore
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=Default] Initialized channel manager
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=Default] Current working directory: /storage/log/vmware/vmon
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=ThreadPool] Catch work item exceptions disabled.
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=FairScheduler] Priority level 4 is now active.
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=WorkQueue.vmacoreDefaultIOCompletionQueue] Created: WorkQueue.vmacoreDefaultIOCompletionQueue, type = fair, priority = 4, itemWeight = 1
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=FairScheduler] Priority level 8 is now active.
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=WorkQueue.vmacoreDefaultIOQueue] Created: WorkQueue.vmacoreDefaultIOQueue, type = fair, priority = 8, itemWeight = 1
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=FairScheduler] Priority level 16 is now active.
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=WorkQueue.vmacoreDefaultLongTaskQueue] Created: WorkQueue.vmacoreDefaultLongTaskQueue, type = fair, priority = 16, itemWeight = 1
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=ThreadPool] Registered foreign worker - allocated: 1, idle: 0
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=ThreadPool] Registered foreign worker - allocated: 2, idle: 0
2021-10-12T18:43:57.797+02:00 info vcha[01727] [Originator@6876 sub=ThreadPool] Registered foreign worker - allocated: 3, idle: 0
2021-10-12T18:43:57.798+02:00 info vcha[01727] [Originator@6876 sub=ThreadPool] Registered foreign worker - allocated: 4, idle: 0
2021-10-12T18:43:57.799+02:00 info vcha[01768] [Originator@6876 sub=ThreadPool] Entering worker thread loop
2021-10-12T18:43:57.799+02:00 info vcha[01767] [Originator@6876 sub=ThreadPool] Entering worker thread loop
2021-10-12T18:43:57.801+02:00 info vcha[01769] [Originator@6876 sub=ThreadPool] Entering worker thread loop
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=ThreadPool] Thread pool fair initial threads spawned. IO: 2, Min workers: 4, Max workers: 13, Reservation ratio: 9
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Default] Syscommand enabled: true
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Default] ReaperManager Initialized
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Default] Setting up signal handlers
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Libs] DictionaryLoad: Cannot open file "/etc/vmware/config": No such file or directory.
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Libs] [msg.dictionary.load.openFailed] Cannot open file "/etc/vmware/config": No such file or directory.
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Libs] PREF Optional preferences file not found at /etc/vmware/config. Using default values.
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Libs] Could not expand environment variable HOME.
2021-10-12T18:43:57.801+02:00 info vcha[01727] [Originator@6876 sub=Libs] Could not expand environment variable HOME.
2021-10-12T18:43:57.801+02:00 info vcha[01772] [Originator@6876 sub=ThreadPool] Entering IO thread loop
2021-10-12T18:43:57.801+02:00 info vcha[01770] [Originator@6876 sub=ThreadPool] Entering worker thread loop
2021-10-12T18:43:57.801+02:00 info vcha[01773] [Originator@6876 sub=ThreadPool] Entering fair thread loop
2021-10-12T18:43:57.801+02:00 info vcha[01768] [Originator@6876 sub=ThreadPool] Spawning additional worker - allocated: 5, idle: 0
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] DictionaryLoad: Cannot open file "/usr/lib/vmware/settings": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] [msg.dictionary.load.openFailed] Cannot open file "/usr/lib/vmware/settings": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] PREF Optional preferences file not found at /usr/lib/vmware/settings. Using default values.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] DictionaryLoad: Cannot open file "/usr/lib/vmware/config": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] [msg.dictionary.load.openFailed] Cannot open file "/usr/lib/vmware/config": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] PREF Optional preferences file not found at /usr/lib/vmware/config. Using default values.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] DictionaryLoad: Cannot open file "~/.vmware/config": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] [msg.dictionary.load.openFailed] Cannot open file "~/.vmware/config": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] PREF Optional preferences file not found at ~/.vmware/config. Using default values.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] DictionaryLoad: Cannot open file "~/.vmware/preferences": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] [msg.dictionary.load.openFailed] Cannot open file "~/.vmware/preferences": No such file or directory.
2021-10-12T18:43:57.802+02:00 info vcha[01727] [Originator@6876 sub=Libs] PREF Optional preferences file not found at ~/.vmware/preferences. Using default values.
2021-10-12T18:43:57.804+02:00 info vcha[01727] [Originator@6876 sub=Libs] lib/ssl: OpenSSL using FIPS_drbg for RAND
2021-10-12T18:43:57.804+02:00 info vcha[01727] [Originator@6876 sub=Libs] lib/ssl: protocol list tls1.2
2021-10-12T18:43:57.804+02:00 info vcha[01727] [Originator@6876 sub=Libs] lib/ssl: protocol list tls1.2 (openssl flags 0x17000000)
2021-10-12T18:43:57.804+02:00 info vcha[01727] [Originator@6876 sub=Libs] lib/ssl: cipher list ECDHE+AESGCM:RSA+AESGCM:ECDHE+AES:RSA+AES
2021-10-12T18:43:57.804+02:00 info vcha[01727] [Originator@6876 sub=Libs] lib/ssl: curves list prime256v1:secp384r1:secp521r1
2021-10-12T18:43:57.805+02:00 info vcha[01771] [Originator@6876 sub=ThreadPool] Entering IO thread loop
2021-10-12T18:43:57.805+02:00 info vcha[01774] [Originator@6876 sub=ThreadPool] Entering worker thread loop
2021-10-12T18:43:57.825+02:00 info vcha[01727] [Originator@6876 sub=Default] Vmacore::InitSSL: handshakeTimeoutUs = 20000000
2021-10-12T18:43:57.825+02:00 info vcha[01727] [Originator@6876 sub=Default] Service is running in FIPS mode.
2021-10-12T18:43:57.825+02:00 info vcha[01727] [Originator@6876 sub=Default] Creating SSL Contexts
2021-10-12T18:43:57.827+02:00 error vcha[01727] [Originator@6876 sub=Default] Failed to initialize the SSL context: N7Vmacore6Crypto15CryptoExceptionE(Crypto Exception: error:02001002:system library:fopen:No such file or directory: unable to load BIO)
--> [context]zKq7AVECAQAAAEUWGAEOdmNoYQAAcnY0bGlidm1hY29yZS5zbwAAAaopAAmfKgBDaS8AJF8lAGlqJQAOcyUAdHMlAUHYCHZjaGEAAbA+BgGMDgYBiZcFAlcrAmxpYmMuc28uNgABQQEG[/context]
2021-10-12T18:43:57.830+02:00 panic vcha[01727] [Originator@6876 sub=Default]
-->
--> Panic: Failed to initialize the SSL context.
--> Backtrace:
--> [backtrace begin] product: vCenterHA, version: 7.0.2, build: build-18355781, tag: vcha, cpu: x86_64, os: linux, buildType: release
--> backtrace[00] libvmacore.so[0x003477F7]
--> backtrace[01] libvmacore.so[0x0029AA2D]: Vmacore::System::Stacktrace::CaptureFullWork(unsigned int)
--> backtrace[02] libvmacore.so[0x002A9E47]: Vmacore::System::SystemFactory::CreateBacktrace(Vmacore::Ref<Vmacore::System::Backtrace>&)
--> backtrace[03] libvmacore.so[0x0033AA00]
--> backtrace[04] libvmacore.so[0x0033AB24]: Vmacore::PanicExit(char const*)
--> backtrace[05] libvmacore.so[0x002FE851]
--> backtrace[06] libvmacore.so[0x002FE8EF]
--> backtrace[07] vcha[0x0008DA22]
--> backtrace[08] vcha[0x00063EB0]
--> backtrace[09] vcha[0x00060E8C]
--> backtrace[10] vcha[0x00059789]
--> backtrace[11] libc.so.6[0x00022B57]
--> backtrace[12] vcha[0x00060141]
--> [backtrace end]

 

All certificates are valid and within their date of operations. There has been no system change or update.

Any idea how to reactivate the service? Thanks

Labels (2)
7 Replies
g3nrix
Contributor
Contributor

Same problem after upgrading cluster hosts. ESXi version_7.0.2-0.25.18538813. VCSA backup now doesn't work.

 
 

 

 

0 Kudos
balc50
Contributor
Contributor

And same exact error found in vcha log even on 7.0.3, build-19192837.

No fix found yet?

0 Kudos
g3nrix
Contributor
Contributor

You should have a snapshot of your vCenter VM by following the below steps:

    1. Access the Host Client from where the vCenter VM is running.
    2. Go to the vCenter VM and then "Actions" and "Take a snapshot"
    3. Make sure to keep the checkbox of "Take it with the Virtual Machine's memory"

Disable the VCHA service as it is not used on the vCenter using the below commands:

    1. cd /usr/lib/vmware-vmon
    2. vmon-cli -S DISABLED -U vcha

Retrying the backup resulted in an error: "Db health is UNHEALTHY, Backup Failed. Disable health check to take backup in current state." The solution presented at https://kb.vmware.com/s/article/86084 helped. The backup is now working

balc50
Contributor
Contributor

Thank you for reply, i tried and did them all steps, from snapshot to db check but in my case the vcha was always disabled (but ran the step also now) and also the backup config had the 'db health check' disabled - but anyway, i still got same message that "Invalid vCenter Server Status: All required services are not up! Stopped services: 'vcha' ".

The funny bit is that we have other vcsa and all other have vcha disabled and are at same build version yet none have this error for backup. I'll open a case with support when our contact guy will be back or see if latest update is applicable and maybe will 'cure' this vc.

0 Kudos
mdraz209
Contributor
Contributor

Just checking in to see if you have had any success with addressing this issue. I am now encountering it on 7.0.3.00800 with the exact same symptoms with the vcha service and the "Failed to initialize the SSL context" error in the logs. Thanks!

0 Kudos
Zarranto23
Contributor
Contributor

Hi any update on this topic @balc50 ? some Fix? i receive the same error after the the upgrade to 7.0 up 3j. 

Thanks  a lot

0 Kudos