VMware Cloud Community
paintballer991
Contributor
Contributor

Backup Fails - Failed to clean up backup child processes

 

Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 1996, in BackupVCDB
    br_state.isFastBackupRequired())
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 570, in _start_pg_backup
    "backupfast" : 'true' if backup_fast else 'false'})
psycopg2.OperationalError: terminating connection due to administrator command
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

2021-08-28T03:35:55.471 [20210828-033509-18356314] [VCDBBackup:PID-29574] [Proc::UpdateExceptionStatus:Proc.py:383] ERROR: terminating connection due to administrator command
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

2021-08-28T03:35:55.473 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:285] INFO: Check Feature Switch PG_TELEMETRY state
2021-08-28T03:35:55.474 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:290] INFO: Check the telemetry conf file
2021-08-28T03:35:55.474 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:294] INFO: Check configuration parameter vcenter.telemetry
2021-08-28T03:35:55.478 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:298] INFO: Telemetry for Postgres is enabled
2021-08-28T03:35:55.478 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::get_vc_version:telemetry.py:306] INFO: Get vCenter version from /etc/vmware/.buildInfo
2021-08-28T03:35:55.478 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::get_vc_version:telemetry.py:312] INFO: vCenter version is 7.0U1a
2021-08-28T03:35:55.479 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDB:VCDB.py:2083] INFO: Telemetry command is ['/opt/vmware/vpostgres/current/bin/vmw_vpg_config/pg_trigger_telemetry.py', '--event-type', 'backup', '--data1', 'Full Backup', '--data3', '7.0U1a', '--data2', 'Success']
2021-08-28T03:35:55.479 [20210828-033509-18356314] [VCDBBackup:PID-29574] [Proc::RunCmdForOutput:Proc.py:537] INFO: Executing command: ['/opt/vmware/vpostgres/current/bin/vmw_vpg_config/pg_trigger_telemetry.py', '--event-type', 'backup', '--data1', 'Full Backup', '--data3', '7.0U1a', '--data2', 'Success'].
2021-08-28T03:35:55.759 [20210828-033509-18356314] [MainProcess:PID-29303] [FtpStorageIOLib::_process_curl_output:FtpStorageIOLib.py:129] ERROR: ftp cmd failed. RC: 21, Err: curl: (21) QUOT command failed with 500
, Cmd: ['/usr/bin/curl', '--fail', '-u', 'admin:****', '--connect-timeout', '10', '--noproxy', '*', '--silent', '--show-error', '-Q', 'dele /vCenter/sn_vcenter.domain.org/M_7.0.2.00400_20210828-033509_/config_files.tar.gz', 'ftp://10.10.21.10/vCenter/sn_vcenter.domain.org/M_7.0.2.00400_20210828-033509_/']
2021-08-28T03:35:55.778 [20210828-033509-18356314] [MainProcess:PID-29303] [BackupManager::Cleanup:BackupManager.py:396] WARNING: Ignore to clean up failed backup files, due to issue: 'Plugin error occurred. ErrCode: 102, Args: ()'.
2021-08-28T03:35:55.781 [20210828-033509-18356314] [MainProcess:PID-29303] [BackupManager::HandleBackupCleanup:BackupManager.py:440] ERROR: Failed to cleanup the backup job. Error: Failed to clean up the backup job.
2021-08-28T03:35:56.23 [20210828-033509-18356314] [VCDB-WAL-Backup:PID-29597] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-28T03:35:57.32 [20210828-033509-18356314] [VCDB-WAL-Backup:PID-29597] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-28T03:35:58.39 [20210828-033509-18356314] [VCDB-WAL-Backup:PID-29597] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-28T03:35:58.543 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDB:VCDB.py:2085] INFO: Success to push telemetry data for backup
2021-08-28T03:35:58.549 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDBCleanup:VCDB.py:2102] INFO: Finishing full database backup
2021-08-28T03:35:58.616 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDBCleanup:VCDB.py:2105] INFO: Successfully cleaned up for VCDB backup.
2021-08-28T03:35:58.638 [20210828-033509-18356314] [MainProcess:PID-29303] [vpxdevent_lib::dispatch_events:vpxdevent_lib.py:275] INFO: Event com.vmware.applmgmt.backup.job.failed.event successfully posted to http://localhost:8085/sdk
2021-08-28T03:35:58.701 [20210828-033509-18356314] [MainProcess:PID-29303] [BackupManager::main:BackupManager.py:648] INFO: Backup job failed.

 

I'm trying to backup vCenter outside of just Veeam and for the life of me I cannot get it to just work.

 

FTP access and all that works fine, the backup process itself fails. In the log this is the only error I'm seeing.

 

 

 

2021-08-27T07:18:04.947 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:372] ERROR: Failed to clean up backup child processes.
Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/util/Proc.py", line 251, in CleanupChildProcesses
    proc.wait(timeout=30)
  File "/usr/lib/python3.7/site-packages/psutil/__init__.py", line 1262, in wait
    return self._proc.wait(timeout)
  File "/usr/lib/python3.7/site-packages/psutil/_pslinux.py", line 1459, in wrapper
    return fun(self, *args, **kwargs)
  File "/usr/lib/python3.7/site-packages/psutil/_pslinux.py", line 1637, in wait
    return _psposix.wait_pid(self.pid, timeout, self._name)
  File "/usr/lib/python3.7/site-packages/psutil/_psposix.py", line 104, in wait_pid
    delay = check_timeout(delay)
  File "/usr/lib/python3.7/site-packages/psutil/_psposix.py", line 66, in check_timeout
    raise TimeoutExpired(timeout, pid=pid, name=proc_name)
psutil._exceptions.TimeoutExpired: psutil.TimeoutExpired timeout after 30 seconds (pid=14014)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/BackupManager.py", line 369, in Cleanup
    CleanupChildProcesses()
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/util/Proc.py", line 259, in CleanupChildProcesses
    raise Exception("%s" % str(e))
Exception: psutil.TimeoutExpired timeout after 30 seconds (pid=14014)
2021-08-27T07:18:04.977 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:375] INFO: Cleaning up all sizeFiles.
2021-08-27T07:18:04.978 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up ConfigFiles.
2021-08-27T07:18:04.978 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up ComponentScripts.
2021-08-27T07:18:04.978 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up VCDB.
2021-08-27T07:18:04.980 [20210827-060235-18356314] [MainProcess:PID-13866] [VCDB::BackupVCDBCleanup:VCDB.py:2102] INFO: Finishing full database backup
2021-08-27T07:18:04.982 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:05.20 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:372] ERROR: Failed to clean up backup child processes.
Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/util/Proc.py", line 251, in CleanupChildProcesses
    proc.wait(timeout=30)
  File "/usr/lib/python3.7/site-packages/psutil/__init__.py", line 1262, in wait
    return self._proc.wait(timeout)
  File "/usr/lib/python3.7/site-packages/psutil/_pslinux.py", line 1459, in wrapper
    return fun(self, *args, **kwargs)
  File "/usr/lib/python3.7/site-packages/psutil/_pslinux.py", line 1637, in wait
    return _psposix.wait_pid(self.pid, timeout, self._name)
  File "/usr/lib/python3.7/site-packages/psutil/_psposix.py", line 104, in wait_pid
    delay = check_timeout(delay)
  File "/usr/lib/python3.7/site-packages/psutil/_psposix.py", line 66, in check_timeout
    raise TimeoutExpired(timeout, pid=pid, name=proc_name)
psutil._exceptions.TimeoutExpired: psutil.TimeoutExpired timeout after 30 seconds (pid=44909)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/BackupManager.py", line 369, in Cleanup
    CleanupChildProcesses()
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/util/Proc.py", line 259, in CleanupChildProcesses
    raise Exception("%s" % str(e))
Exception: psutil.TimeoutExpired timeout after 30 seconds (pid=44909)
2021-08-27T07:18:05.23 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:375] INFO: Cleaning up all sizeFiles.
2021-08-27T07:18:05.24 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up ConfigFiles.
2021-08-27T07:18:05.25 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up ComponentScripts.
2021-08-27T07:18:05.25 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up VCDB.
2021-08-27T07:18:05.27 [20210827-051335-18356314] [MainProcess:PID-44800] [VCDB::BackupVCDBCleanup:VCDB.py:2102] INFO: Finishing full database backup
2021-08-27T07:18:04.988 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:389] ERROR: Failed to do the necessary cleanup for the part VCDB at backup cleanup.
Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/BackupManager.py", line 384, in Cleanup
    backupObj.backupParts[part]['cleanup'](backupObj.args)
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 2103, in BackupVCDBCleanup
    _cleanup_full_database_backup()
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 1337, in _cleanup_full_database_backup
    server_port = _get_postgres_server_port()
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 1815, in _get_postgres_server_port
    server_port = pg_params.ReadConfigParam(pgsql_conf, 'port')
  File "/opt/vmware/vpostgres/current/share/python-modules/vpostgres/params.py", line 62, in ReadConfigParam
    with open(filepath, 'r') as f:
FileNotFoundError: [Errno 2] No such file or directory: '/storage/db/vpostgres/postgresql.conf'
2021-08-27T07:18:05.28 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:389] ERROR: Failed to do the necessary cleanup for the part VCDB at backup cleanup.
Traceback (most recent call last):
Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/BackupManager.py", line 384, in Cleanup
    backupObj.backupParts[part]['cleanup'](backupObj.args)
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 2103, in BackupVCDBCleanup
    _cleanup_full_database_backup()
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 1337, in _cleanup_full_database_backup
    server_port = _get_postgres_server_port()
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 1815, in _get_postgres_server_port
    server_port = pg_params.ReadConfigParam(pgsql_conf, 'port')
  File "/opt/vmware/vpostgres/current/share/python-modules/vpostgres/params.py", line 62, in ReadConfigParam
    with open(filepath, 'r') as f:
FileNotFoundError: [Errno 2] No such file or directory: '/storage/db/vpostgres/postgresql.conf'
2021-08-27T07:18:05.46 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up Lotus.
2021-08-27T07:18:05.46 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up Lotus.
2021-08-27T07:18:05.52 [20210827-060235-18356314] [MainProcess:PID-13866] [Lotus::BackupLotusCleanup:Lotus.py:127] INFO: Successfully completed Lotus cleanup.
2021-08-27T07:18:05.52 [20210827-051335-18356314] [MainProcess:PID-44800] [Lotus::BackupLotusCleanup:Lotus.py:127] INFO: Successfully completed Lotus cleanup.
2021-08-27T07:18:05.52 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up StatsMonitorDB.
2021-08-27T07:18:05.52 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up StatsMonitorDB.
2021-08-27T07:18:05.52 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up VTSDB.
2021-08-27T07:18:05.52 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:383] INFO: Cleaning up VTSDB.
2021-08-27T07:18:05.53 [20210827-060235-18356314] [MainProcess:PID-13866] [VTSDB::BackupVTSDBCleanup:VTSDB.py:237] INFO: Successfully cleaned up for VTSDB backup.
2021-08-27T07:18:05.53 [20210827-051335-18356314] [MainProcess:PID-44800] [VTSDB::BackupVTSDBCleanup:VTSDB.py:237] INFO: Successfully cleaned up for VTSDB backup.
2021-08-27T07:18:05.53 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::Cleanup:BackupManager.py:392] INFO: Cleaning up failed backup files.
2021-08-27T07:18:05.53 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:392] INFO: Cleaning up failed backup files.
2021-08-27T07:18:05.214 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:05.522 [20210827-051335-18356314] [MainProcess:PID-44800] [FtpStorageIOLib::_process_curl_output:FtpStorageIOLib.py:123] ERROR: ftp quote cmd failed. Err: curl: (9) Server denied you to change to the given directory
, Cmd: ['/usr/bin/curl', '--fail', '-u', 'admin:****', '--connect-timeout', '10', '--noproxy', '*', '--silent', '--show-error', '--list-only', 'ftp://10.10.21.10/vCenter/sn_vcenter.domain.org/M_7.0.2.00400_20210827-051335_/']
2021-08-27T07:18:05.528 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::Cleanup:BackupManager.py:396] WARNING: Ignore to clean up failed backup files, due to issue: 'Plugin error occurred. ErrCode: 3, Args: ()'.
2021-08-27T07:18:05.529 [20210827-051335-18356314] [MainProcess:PID-44800] [BackupManager::HandleBackupCleanup:BackupManager.py:440] ERROR: Failed to cleanup the backup job. Error: Failed to clean up the backup job.
2021-08-27T07:18:05.712 [20210827-051335-18356314] [MainProcess:PID-44800] [br_events::post_br_event:br_events.py:40] ERROR: Failed to dispatch event com.vmware.applmgmt.backup.job.cancel.event Err: unidentifiable C++ exception
2021-08-27T07:18:05.986 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:06.220 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:06.936 [20210827-060235-18356314] [MainProcess:PID-13866] [BackupManager::HandleBackupCleanup:BackupManager.py:440] ERROR: Failed to cleanup the backup job. Error: Failed to clean up the backup job.
2021-08-27T07:18:06.957 [20210827-060235-18356314] [MainProcess:PID-13866] [br_events::post_br_event:br_events.py:40] ERROR: Failed to dispatch event com.vmware.applmgmt.backup.job.cancel.event Err: unidentifiable C++ exception
2021-08-27T07:18:06.989 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:07.225 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:07.993 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:08.231 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:08.997 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:09.239 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:10.3 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:10.244 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:11.14 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:11.249 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:12.21 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:12.253 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:13.26 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:13.257 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:14.30 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:14.266 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:15.34 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:15.274 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:16.40 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:16.279 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:17.43 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:17.283 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:18.47 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:18.288 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:19.51 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:19.293 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:20.55 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:20.297 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:21.59 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:21.301 [20210827-060235-18356314] [VCDB-WAL-Backup:PID-14042] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-27T07:18:22.63 [20210827-051335-18356314] [VCDB-WAL-Backup:PID-44933] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.

 

 

 

 

I found this thread - https://communities.vmware.com/t5/VMware-vCenter-Discussions/File-Based-Backup-7-0-2-Build-17920168-...

 

However it has the correct info in the /issue so no issue there. CUrrent stopped services during and after the backup failure:

 

 

applmgmt observability-vapi vmcam vmware-analytics vmware-hvc vmware-imagebuilder vmware-netdumper vmware-rbd-watchdog vmware-vcha

 

 

 

This has been really flaky since upgrading from 7.0.2.0000 to the current 7.0.2.0400 so I want to update it and do a fresh rebuild.

EDIT: Fixed the stopped service's, forgot reboots I have to manually start a handful of these. This is the new/recent backup fail log entry:

Traceback (most recent call last):
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 1996, in BackupVCDB
    br_state.isFastBackupRequired())
  File "/usr/lib/applmgmt/backup_restore/py/vmware/appliance/backup_restore/components/VCDB.py", line 570, in _start_pg_backup
    "backupfast" : 'true' if backup_fast else 'false'})
psycopg2.OperationalError: terminating connection due to administrator command
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

2021-08-28T03:35:55.471 [20210828-033509-18356314] [VCDBBackup:PID-29574] [Proc::UpdateExceptionStatus:Proc.py:383] ERROR: terminating connection due to administrator command
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

2021-08-28T03:35:55.473 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:285] INFO: Check Feature Switch PG_TELEMETRY state
2021-08-28T03:35:55.474 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:290] INFO: Check the telemetry conf file
2021-08-28T03:35:55.474 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:294] INFO: Check configuration parameter vcenter.telemetry
2021-08-28T03:35:55.478 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::check_telemetry_enabled:telemetry.py:298] INFO: Telemetry for Postgres is enabled
2021-08-28T03:35:55.478 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::get_vc_version:telemetry.py:306] INFO: Get vCenter version from /etc/vmware/.buildInfo
2021-08-28T03:35:55.478 [20210828-033509-18356314] [VCDBBackup:PID-29574] [telemetry::get_vc_version:telemetry.py:312] INFO: vCenter version is 7.0U1a
2021-08-28T03:35:55.479 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDB:VCDB.py:2083] INFO: Telemetry command is ['/opt/vmware/vpostgres/current/bin/vmw_vpg_config/pg_trigger_telemetry.py', '--event-type', 'backup', '--data1', 'Full Backup', '--data3', '7.0U1a', '--data2', 'Success']
2021-08-28T03:35:55.479 [20210828-033509-18356314] [VCDBBackup:PID-29574] [Proc::RunCmdForOutput:Proc.py:537] INFO: Executing command: ['/opt/vmware/vpostgres/current/bin/vmw_vpg_config/pg_trigger_telemetry.py', '--event-type', 'backup', '--data1', 'Full Backup', '--data3', '7.0U1a', '--data2', 'Success'].
2021-08-28T03:35:55.759 [20210828-033509-18356314] [MainProcess:PID-29303] [FtpStorageIOLib::_process_curl_output:FtpStorageIOLib.py:129] ERROR: ftp cmd failed. RC: 21, Err: curl: (21) QUOT command failed with 500
, Cmd: ['/usr/bin/curl', '--fail', '-u', 'admin:****', '--connect-timeout', '10', '--noproxy', '*', '--silent', '--show-error', '-Q', 'dele /vCenter/sn_vcenter.domain.org/M_7.0.2.00400_20210828-033509_/config_files.tar.gz', 'ftp://10.10.21.10/vCenter/sn_vcenter.domain.org/M_7.0.2.00400_20210828-033509_/']
2021-08-28T03:35:55.778 [20210828-033509-18356314] [MainProcess:PID-29303] [BackupManager::Cleanup:BackupManager.py:396] WARNING: Ignore to clean up failed backup files, due to issue: 'Plugin error occurred. ErrCode: 102, Args: ()'.
2021-08-28T03:35:55.781 [20210828-033509-18356314] [MainProcess:PID-29303] [BackupManager::HandleBackupCleanup:BackupManager.py:440] ERROR: Failed to cleanup the backup job. Error: Failed to clean up the backup job.
2021-08-28T03:35:56.23 [20210828-033509-18356314] [VCDB-WAL-Backup:PID-29597] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-28T03:35:57.32 [20210828-033509-18356314] [VCDB-WAL-Backup:PID-29597] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-28T03:35:58.39 [20210828-033509-18356314] [VCDB-WAL-Backup:PID-29597] [VCDB::_backup_wal_files:VCDB.py:797] INFO: VCDB backup WAL start not received yet.
2021-08-28T03:35:58.543 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDB:VCDB.py:2085] INFO: Success to push telemetry data for backup
2021-08-28T03:35:58.549 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDBCleanup:VCDB.py:2102] INFO: Finishing full database backup
2021-08-28T03:35:58.616 [20210828-033509-18356314] [VCDBBackup:PID-29574] [VCDB::BackupVCDBCleanup:VCDB.py:2105] INFO: Successfully cleaned up for VCDB backup.
2021-08-28T03:35:58.638 [20210828-033509-18356314] [MainProcess:PID-29303] [vpxdevent_lib::dispatch_events:vpxdevent_lib.py:275] INFO: Event com.vmware.applmgmt.backup.job.failed.event successfully posted to http://localhost:8085/sdk
2021-08-28T03:35:58.701 [20210828-033509-18356314] [MainProcess:PID-29303] [BackupManager::main:BackupManager.py:648] INFO: Backup job failed.
Labels (1)
0 Kudos
0 Replies