swift-ringbuilder exceeded timeout

Bug #1776550 reported by Michele Baldessari
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
tripleo
Expired
Medium
Unassigned

Bug Description

So while working on controller scale up functionality (from one controller to three), I observed the following error:
2018-06-12 18:19:24Z [overcloud-AllNodesDeploySteps-fnaae2ekghjo-ControllerDeployment_Step1-u46x2uh4wyqp.0]: UPDATE_FAILED Error: resources[0]: Deployment to server failed: deploy_status_co
de : Deployment exited with non-zero status code: 2
...

The container that fails is:
e95a11d3c6f9 192.168.24.1:8787/tripleoqueens/centos-binary-swift-proxy-server:current-tripleo-rdo "/var/lib/docker-p..." 36 minutes ago Exited (6) 34 minutes ago docker-puppet-swift_ringbuilder

Looking at the docker logs from controller-0 (192.168.24.15) we have:
Jun 12 18:18:11 overcloud-controller-0 dockerd-current[17890]: Error: Command exceeded timeout
Jun 12 18:18:11 overcloud-controller-0 dockerd-current[17890]: Error: /Stage[main]/Tripleo::Profile::Base::Swift::Ringbuilder/Exec[fetch_swift_ring_tarball]/returns: change from notrun to 0 3 failed: Command exceeded timeout

Funnily enough when I try the curl command by hand it succeeded:
URL="http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc04&temp_url_expires=1528912449"
curl -g --insecure --retry 3 "$URL" -o /tmp/swift-rings.tgz

[root@overcloud-controller-0 var]# tar tvf /tmp/swift-rings.tgz
-rw-r--r-- swift/swift 4765 2018-06-12 16:34 etc/swift/account.builder
-rw-r--r-- swift/swift 4765 2018-06-12 16:34 etc/swift/container.builder
-rw-r--r-- swift/swift 4765 2018-06-12 16:34 etc/swift/object.builder
-rw-r--r-- root/root 204 2018-06-12 16:34 etc/swift/account.ring.gz
-rw-r--r-- root/root 206 2018-06-12 16:34 etc/swift/container.ring.gz
-rw-r--r-- root/root 202 2018-06-12 16:34 etc/swift/object.ring.gz
drwxr-xr-x swift/swift 0 2018-06-12 16:34 etc/swift/backups/
-rw-r--r-- swift/swift 2443 2018-06-12 16:34 etc/swift/backups/1528821265.object.builder
-rw-r--r-- swift/swift 2443 2018-06-12 16:34 etc/swift/backups/1528821265.account.builder
-rw-r--r-- swift/swift 2443 2018-06-12 16:34 etc/swift/backups/1528821266.container.builder
-rw-r--r-- root/root 213 2018-06-12 16:34 etc/swift/backups/1528821270.object.ring.gz
-rw-r--r-- root/root 4765 2018-06-12 16:34 etc/swift/backups/1528821270.object.builder
-rw-r--r-- root/root 215 2018-06-12 16:34 etc/swift/backups/1528821271.account.ring.gz
-rw-r--r-- root/root 4765 2018-06-12 16:34 etc/swift/backups/1528821271.account.builder
-rw-r--r-- root/root 217 2018-06-12 16:34 etc/swift/backups/1528821272.container.ring.gz
-rw-r--r-- root/root 4765 2018-06-12 16:34 etc/swift/backups/1528821272.container.builder

Looking at the undercloud log a bit before Jun 12 18:18:11 which is when it failed we see:
 [root@undercloud ~]# grep overcloud-swift-rings /var/log/swift/swift.log |grep -e "Jun 12 1[78]" [32/1978]Jun 12 17:51:18 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:17:51:18 +0000] "HEAD /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 204 - "HEAD http://192.16
8.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "tx00880ab49cd9459e9890f-005b200816" "proxy-server 16602" 0.0012 "-" 18444 0
Jun 12 17:51:18 undercloud proxy-server: - - 12/Jun/2018/17/51/18 HEAD /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 204 - Swift - - - - tx00880ab49cd9459e9890f-005b200816 - 0.0035 RL - 1528825878.895716906 1528825878.899172068 0
Jun 12 17:51:18 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:17:51:18 +0000] "GET /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 200 1605 "GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "tx00880ab49cd9459e9890f-005b200816" "proxy-server 16602" 0.0018 "-" 18443 0
Jun 12 17:51:18 undercloud proxy-server: 192.168.24.1 192.168.24.1 12/Jun/2018/17/51/18 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 200 - pyt
hon-swiftclient-3.5.0 gAAAAABbIAf-9Sng... - 1605 - tx00880ab49cd9459e9890f-005b200816 - 0.0107 - - 1528825878.894768953 1528825878.905427933 0
Jun 12 17:54:08 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:17:54:08 +0000] "HEAD /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 204 - "HEAD http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "tx930ab9773da9435d8b2a5-005b2008c0" "proxy-server 16603" 0.0014 "-" 18445 0
Jun 12 17:54:08 undercloud proxy-server: 192.168.24.1 192.168.24.1 12/Jun/2018/17/54/08 HEAD /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 204 - python-swiftclient-3.5.0 gAAAAABbIAf-9Sng... - - - tx930ab9773da9435d8b2a5-005b2008c0 - 0.0062 - - 1528826048.969676971 1528826048.975856066 0
Jun 12 17:54:09 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:17:54:09 +0000] "HEAD /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 204 - "HEAD http://192.16
8.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "tx8be9e186c9924e2dbff34-005b2008c1" "proxy-server 16602" 0.0015 "-" 18445 0
Jun 12 17:54:09 undercloud proxy-server: 192.168.24.1 192.168.24.1 12/Jun/2018/17/54/09 HEAD /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 204 - python-swiftclient-3.5.0 gAAAAABbIAf-9Sng... - - - tx8be9e186c9924e2dbff34-005b2008c1 - 0.0060 - - 1528826049.070175886 1528826049.076158047 0
Jun 12 17:54:39 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:17:54:39 +0000] "HEAD /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 204 - "HEAD http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "txe8914030799749268a7a2-005b2008df" "proxy-server 16603" 0.0014 "-" 18445 0
Jun 12 17:54:39 undercloud proxy-server: 192.168.24.1 192.168.24.1 12/Jun/2018/17/54/39 HEAD /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 204 - py
thon-swiftclient-3.5.0 gAAAAABbIAf-9Sng... - - - txe8914030799749268a7a2-005b2008df - 0.0064 - - 1528826079.160125971 1528826079.166570902 0
Jun 12 18:16:04 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:18:16:04 +0000] "HEAD /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 204 - "HEAD http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "tx945652e201fe42e294a6d-005b200de4" "proxy-server 16602" 0.0018 "-" 18443 0
Jun 12 18:16:04 undercloud proxy-server: - - 12/Jun/2018/18/16/04 HEAD /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 204 - Swift - - - - tx945652e201fe42e294a6d-005b200de4 - 0.0046 TU - 1528827364.922332048 1528827364.926944971 0
Jun 12 18:16:04 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:16:04 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc
04" "tx945652e201fe42e294a6d-005b200de4" "proxy-server 16602" 0.0007 "-" 18584 0
Jun 12 18:16:06 undercloud proxy-server: 192.168.24.9 192.168.24.9 12/Jun/2018/18/16/06 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_expires%3D1528912449%26temp_url_sig%3De235dfb34dd32381a298a85b32e9e8268914dc04 HTTP/1.0 200 - curl/7.29.0 - - 2031 - tx945652e201fe42e294a6d-005b200de4 - 1.9609 - - 1528827364.921262026 15288273
66.882137060 0
Jun 12 18:16:20 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:18:16:20 +0000] "PUT /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 201 - "PUT http://192.168.24.1:8080/1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" "tx13a254a0c80d4e93a6a2c-005b200df4" "object-server 18586" 0.0005 "-" 18441
 0
Jun 12 18:16:20 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:16:20 +0000] "PUT /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 201 - "PUT
 http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912479&temp_url_sig=bba94ff02f2d5aed3e79ac67b23eeaaec7425bf2"
 "tx13a254a0c80d4e93a6a2c-005b200df4" "proxy-server 16605" 0.0328 "-" 18586 0
Jun 12 18:16:20 undercloud proxy-server: 192.168.24.9 192.168.24.9 12/Jun/2018/18/16/20 PUT /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_expi
res%3D1528912479%26temp_url_sig%3Dbba94ff02f2d5aed3e79ac67b23eeaaec7425bf2 HTTP/1.0 201 - curl/7.29.0 - 2031 - - tx13a254a0c80d4e93a6a2c-005b200df4 - 0.0378 - - 1528827380.159341097 15288273
80.197138071 0
Jun 12 18:18:16 undercloud container-server: 192.168.24.1 - - [12/Jun/2018:18:18:16 +0000] "HEAD /1/867/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings" 204 - "HEAD http://192.16
8.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings?format=json" "tx56925513a1a141f2a2bd8-005b200e4a" "proxy-server 16603" 29.4560 "-" 18444 0
Jun 12 18:18:16 undercloud proxy-server: - - 12/Jun/2018/18/18/16 HEAD /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings%3Fformat%3Djson HTTP/1.0 204 - Swift - - - - tx56925513
a1a141f2a2bd8-005b200e4a - 29.4595 TU - 1528827466.838697910 1528827496.298219919 0
Jun 12 18:18:16 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:18:16 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "
GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc
04" "tx56925513a1a141f2a2bd8-005b200e4a" "proxy-server 16603" 0.0010 "-" 18585 0
Jun 12 18:18:17 undercloud proxy-server: 192.168.24.15 192.168.24.15 12/Jun/2018/18/18/17 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_ex
pires%3D1528912449%26temp_url_sig%3De235dfb34dd32381a298a85b32e9e8268914dc04 HTTP/1.0 200 - curl/7.29.0 - - 2031 - tx56925513a1a141f2a2bd8-005b200e4a - 30.5842 - - 1528827466.837025881 15288
27497.421236038 0
Jun 12 18:18:27 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:18:27 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "
GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc
04" "tx86d9d7a96f514343b2bd7-005b200e73" "proxy-server 16605" 0.0007 "-" 18586 0

I cannot see any obvious failure there, which kind of makes me think curl did not even reach the undercloud (?)

Revision history for this message
Michele Baldessari (michele) wrote :

sosreports for the undercloud and controller-0 are here: http://acksyn.org/files/tripleo/sosreports-ctrl-scaleup-swiftringbuild-fail/

Revision history for this message
Michele Baldessari (michele) wrote :
Download full text (4.4 KiB)

 [root@undercloud ~]# grep 'e235dfb34dd32381a298a85b32e9e8268914dc04' /var/log/swift/swift.log
Jun 12 18:16:04 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:16:04 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc04" "tx945652e201fe42e294a6d-005b200de4" "proxy-server 16602" 0.0007 "-" 18584 0
Jun 12 18:16:06 undercloud proxy-server: 192.168.24.9 192.168.24.9 12/Jun/2018/18/16/06 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_expires%3D1528912449%26temp_url_sig%3De235dfb34dd32381a298a85b32e9e8268914dc04 HTTP/1.0 200 - curl/7.29.0 - - 2031 - tx945652e201fe42e294a6d-005b200de4 - 1.9609 - - 1528827364.921262026 1528827366.882137060 0
Jun 12 18:18:16 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:18:16 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc04" "tx56925513a1a141f2a2bd8-005b200e4a" "proxy-server 16603" 0.0010 "-" 18585 0
Jun 12 18:18:17 undercloud proxy-server: 192.168.24.15 192.168.24.15 12/Jun/2018/18/18/17 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_expires%3D1528912449%26temp_url_sig%3De235dfb34dd32381a298a85b32e9e8268914dc04 HTTP/1.0 200 - curl/7.29.0 - - 2031 - tx56925513a1a141f2a2bd8-005b200e4a - 30.5842 - - 1528827466.837025881 1528827497.421236038 0
Jun 12 18:18:27 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:18:27 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc04" "tx86d9d7a96f514343b2bd7-005b200e73" "proxy-server 16605" 0.0007 "-" 18586 0
Jun 12 18:18:27 undercloud proxy-server: 192.168.24.7 192.168.24.7 12/Jun/2018/18/18/27 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_expires%3D1528912449%26temp_url_sig%3De235dfb34dd32381a298a85b32e9e8268914dc04 HTTP/1.0 200 - curl/7.29.0 - - 2031 - tx86d9d7a96f514343b2bd7-005b200e73 - 0.0057 - - 1528827507.837201118 1528827507.842941999 0
Jun 12 18:37:46 undercloud object-server: 192.168.24.1 - - [12/Jun/2018:18:37:46 +0000] "GET /1/927/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz" 200 2031 "GET http://192.168.24.1:8080/v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz?temp_url_expires=1528912449&temp_url_sig=e235dfb34dd32381a298a85b32e9e8268914dc04" "tx8dbc397af4fc4e8494315-005b2012fa" "proxy-server 16605" 0.0006 "-" 18584 0
Jun 12 18:37:46 undercloud proxy-server: 192.168.24.15 192.168.24.15 12/J...

Read more...

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to puppet-tripleo (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/575009

Revision history for this message
Bogdan Dobrelya (bogdando) wrote :

Jun 12 18:18:17 undercloud proxy-server: 192.168.24.15 192.168.24.15 12/Jun/2018/18/18/17 GET /v1/AUTH_4eb73f99e4ac4e9a9b904687023d2b3c/overcloud-swift-rings/swift-rings.tar.gz%3Ftemp_url_ex
pires%3D1528912449%26temp_url_sig%3De235dfb34dd32381a298a85b32e9e8268914dc04 HTTP/1.0 200 - curl/7.29.0 - - 2031 - tx56925513a1a141f2a2bd8-005b200e4a - 30.5842 - - 1528827466.837025881 15288
27497.421236038 0

took 31 sec to complete, is that normal? it may force some default 30sec timers to fail

Revision history for this message
Michele Baldessari (michele) wrote :

So I have this once so far (in a dozen of runs). I wonder if indeed this is a case that during the controller scaleup testing I am overloading the undercloud a bit and it has a hard time coping with it. Maybe an extension of the timeouts is all that is needed here.

Changed in tripleo:
milestone: rocky-3 → rocky-rc1
Changed in tripleo:
milestone: rocky-rc1 → stein-1
Changed in tripleo:
milestone: stein-1 → stein-2
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on puppet-tripleo (master)

Change abandoned by Emilien Macchi (<email address hidden>) on branch: master
Review: https://review.openstack.org/575009
Reason: This patch has no activity for a while, per policy, we abandon it. Feel free to re-open if you think you're working on it.

Changed in tripleo:
milestone: stein-2 → stein-3
Changed in tripleo:
milestone: stein-3 → train-1
Changed in tripleo:
milestone: train-1 → train-2
Changed in tripleo:
milestone: train-2 → train-3
Changed in tripleo:
milestone: train-3 → ussuri-1
Changed in tripleo:
milestone: ussuri-1 → ussuri-2
wes hayutin (weshayutin)
Changed in tripleo:
milestone: ussuri-2 → ussuri-3
wes hayutin (weshayutin)
Changed in tripleo:
status: Triaged → Incomplete
wes hayutin (weshayutin)
Changed in tripleo:
milestone: ussuri-3 → ussuri-rc3
wes hayutin (weshayutin)
Changed in tripleo:
milestone: ussuri-rc3 → victoria-1
Changed in tripleo:
milestone: victoria-1 → victoria-3
Changed in tripleo:
milestone: victoria-3 → wallaby-1
Changed in tripleo:
milestone: wallaby-1 → wallaby-2
Changed in tripleo:
milestone: wallaby-2 → wallaby-3
Revision history for this message
Marios Andreou (marios-b) wrote :

This is an automated action. Bug status has been set to 'Incomplete' and target milestone has been removed due to inactivity. If you disagree please re-set these values and reach out to us on freenode #tripleo

Changed in tripleo:
milestone: wallaby-3 → none
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for tripleo because there has been no activity for 60 days.]

Changed in tripleo:
status: Incomplete → Expired
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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