OpenStack Backup/Restore and DR (Freezer)

Error when tring to remove lvm snapshot

Bug #1596073 reported by Pierre-Arthur MATHIEU
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Backup/Restore and DR (Freezer)
Fix Released
Undecided
Unassigned
OpenStack Backup/Restore and DR (Freezer) newton-2 "n2"

Bug Description

2016-06-22 08:55:27,411 root INFO log file at /var/log/freezer-agent/freezer-agent.log
2016-06-22 08:55:27,411 root INFO [*] Creation of swift client
2016-06-22 08:55:27,418 requests.packages.urllib3.connectionpool INFO Starting new HTTPS connection (1): hlm001-cp1-vip-KEY-API-mgmt
2016-06-22 08:55:27,916 requests.packages.urllib3.connectionpool INFO Starting new HTTPS connection (1): 10.240.20.2
2016-06-22 08:55:28,170 root INFO [*] Job execution Started at: 2016-06-22 08:55:28
2016-06-22 08:55:28,278 root WARNING Using non-INI files for database configuration file is deprecated. Falling back to Regex.
2016-06-22 08:55:28,279 root WARNING INI parser error was: 'builtin_function_or_method' object has no attribute 'StringIO'
2016-06-22 08:55:28,292 root INFO [*] Source LVM Volume: /dev/hlm-vg/mysql
2016-06-22 08:55:28,292 root INFO [*] LVM Volume Group: hlm-vg
2016-06-22 08:55:28,292 root INFO [*] Snapshot name: freezer_backup_snap
2016-06-22 08:55:28,292 root INFO [*] Snapshot size: 1G
2016-06-22 08:55:28,292 root INFO [*] Directory where the lvm snaphost will be mounted on: /var/lib/freezer
2016-06-22 08:55:28,292 root INFO [*] Path to backup (including snapshot): /var/lib/freezer/.
2016-06-22 08:55:28,292 root WARNING [*] Directory /var/lib/freezer found!
2016-06-22 08:55:28,948 root WARNING [*] Logical volume "freezer_backup_snap" created
2016-06-22 08:55:28,964 root INFO [*] File system ext4 found for volume /dev/hlm-vg/mysql
2016-06-22 08:55:29,016 root WARNING [*] Volume /dev/hlm-vg/freezer_backup_snap succesfully mounted on /var/lib/freezer
2016-06-22 08:55:29,119 root WARNING [*] Directory /root/.freezer found!
2016-06-22 08:55:29,119 root INFO Tar engine backup stream enter
2016-06-22 08:55:29,128 root INFO Execution command:
/bin/tar --create -z --warning=none --no-check-device --one-file-system --preserve-permissions --same-owner --seek --ignore-failed-read --listed-incremental=/root/.freezer/tar_metadata_hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0 .
2016-06-22 08:55:35,502 root INFO [*] Uploading file chunk index: hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000
2016-06-22 08:55:35,680 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:55:35,682 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:55:35,682 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:55:35 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'txed4d38b8cc8c4c4da36a6-00576a5287'}
2016-06-22 08:55:35,682 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:55:36,882 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:55:36,882 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:55:36,882 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:55:36 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'tx52f0078aa7af4f049dd0a-00576a5288'}
2016-06-22 08:55:36,882 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:55:39,018 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:55:39,018 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:55:39,018 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:55:38 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'txabdc42ab52d340e7824bb-00576a528a'}
2016-06-22 08:55:39,018 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:55:43,203 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:55:43,204 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:55:43,204 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:55:43 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'tx2cab4fb8c6724ebc84107-00576a528f'}
2016-06-22 08:55:43,204 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:55:51,534 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:55:51,534 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:55:51,534 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:55:51 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'tx04389dd6dd4e4f288f00e-00576a5297'}
2016-06-22 08:55:51,534 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:56:07,743 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:56:07,743 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:56:07,743 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:56:07 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'tx02ed22ea0d864c47a1378-00576a52a7'}
2016-06-22 08:56:07,743 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:56:39,979 swiftclient INFO REQ: curl -i https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 -X PUT -H "Content-Length: 20000000" -H "Content-Type: application/octet-stream" -H "X-Auth-Token: bdad6fec450c4f16..."
2016-06-22 08:56:39,979 swiftclient INFO RESP STATUS: 503 Service Unavailable
2016-06-22 08:56:39,979 swiftclient INFO RESP HEADERS: {u'Date': u'Wed, 22 Jun 2016 08:56:39 GMT', u'Content-Length': u'118', u'Content-Type': u'text/html; charset=UTF-8', u'X-Trans-Id': u'tx54d6ba8c08ab4f5c9f88b-00576a52c7'}
2016-06-22 08:56:39,979 swiftclient INFO RESP BODY: <html><h1>Service Unavailable</h1><p>The server is currently unavailable. Please try again at a later time.</p></html>
2016-06-22 08:56:39,980 swiftclient ERROR Object PUT failed: https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 503 Service Unavailable [first 60 chars of response] <html><h1>Service Unavailable</h1><p>The server is currently
Traceback (most recent call last):
  File "/opt/stack/venv/freezer_agent-20160616T031859Z/lib/python2.7/site-packages/swiftclient/client.py", line 1488, in _retry
    service_token=self.service_token, **kwargs)
  File "/opt/stack/venv/freezer_agent-20160616T031859Z/lib/python2.7/site-packages/swiftclient/client.py", line 1202, in put_object
    http_response_content=body)
ClientException: Object PUT failed: https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 503 Service Unavailable [first 60 chars of response] <html><h1>Service Unavailable</h1><p>The server is currently
2016-06-22 08:56:39,991 root INFO [*] Retrying to upload file chunk index: hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000

...
[A few retries]
...

2016-06-22 09:15:34,697 root INFO [*] Retrying to upload file chunk index: hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000
2016-06-22 09:16:34,744 root INFO [*] Creation of swift client
2016-06-22 09:16:34,745 root CRITICAL [*] Error: add_object: Object PUT failed: https://10.240.20.2:8080/v1/AUTH_937f1b46ba154480bf30b9277e6f35ca/freezer_database_backups_segments/hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0/1466585728/67108864/00000000 503 Service Unavailable [first 60 chars of response] <html><h1>Service Unavailable</h1><p>The server is currently
2016-06-22 09:16:35,084 root INFO [*] Creation of swift client
2016-06-22 09:16:35,093 root INFO [*] Uploading tar meta data file: tar_metadata_hlm001-cp1-c1-m1-mgmt_freezer_mysql_backup_1466585728_0
2016-06-22 09:16:35,095 requests.packages.urllib3.connectionpool INFO Starting new HTTPS connection (1): hlm001-cp1-vip-KEY-API-mgmt
2016-06-22 09:16:35,754 requests.packages.urllib3.connectionpool INFO Starting new HTTPS connection (1): 10.240.20.2
2016-06-22 09:16:36,448 root INFO [*] Volume /var/lib/freezer unmounted
2016-06-22 09:16:36,629 root CRITICAL [*] Critical Error: unable to remove snapshot /dev/hlm-vg/freezer_backup_snap. File descriptor 3 (/var/log/freezer-agent/freezer-scheduler.log) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 4 (socket:[1108986662]) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 5 (/var/log/freezer-agent/freezer-agent.log) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 6 (socket:[1146707843]) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 10 (socket:[1147074155]) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 13 (/dev/urandom) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 14 (socket:[1146051945]) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 15 (socket:[1146405927]) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
File descriptor 16 (/dev/urandom) leaked on lvremove invocation. Parent PID 35472: /opt/stack/venv/freezer_agent-2
  Logical volume hlm-vg/freezer_backup_snap contains a filesystem in use.

Pierre-Arthur MATHIEU (pi3rra)
Changed in freezer:
milestone: none → newton-2
status: New → Fix Released
status: Fix Released → Fix Committed
Pierre-Arthur MATHIEU (pi3rra)
Changed in freezer:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.