search

openvstorage / alba-asdmanager

The ALBA ASD manager is a lightweight library which turns devices into disks which are addressable as key/value disk over an IP and port.
Other
1 stars 3 forks source link

Updating latest fargo causes openvstorage-sdm pkg update to fail on all nodes #178

Closed pploegaert closed 7 years ago

pploegaert commented 7 years ago

Afterwards update of framework was successful

Log shows for each node:

2016-12-02 17:06:13 27400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 184 - ERROR - 10.100.188.32: Error during update: HTTPSConnectionPool(host='10.100.188.32', port=8500): Read timed out. (read timeout=20)
2016-12-02 17:06:23 32400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 185 - ERROR - 10.100.188.32: Failed to perform SDM update. Please check the appropriate logfile on the node
2016-12-02 17:06:23 32400 +0100 - e188-1 - 41618/140579817539392 - lib/update - 186 - ERROR - 10.100.188.32  : Post upgrade action failed with error: Status after upgrade is "started"

Manual reinstallation of this pkg shows no errors:

Reading package lists... Done                                                  
Reading package lists... Done
Building dependency tree       
Reading state information... Done
0 upgraded, 0 newly installed, 1 reinstalled, 0 to remove and 14 not upgraded.
Need to get 0 B/78.8 kB of archives.
After this operation, 0 B of additional disk space will be used.
WARNING: The following packages cannot be authenticated!
  openvstorage-sdm
Install these packages without verification? [y/N] y
(Reading database ... 81298 files and directories currently installed.)
Preparing to unpack .../openvstorage-sdm_1.6.7-rev.476.3674990-1_amd64.deb ...
Unpacking openvstorage-sdm (1.6.7-rev.476.3674990-1) over (1.6.7-rev.476.3674990-1) ...
Setting up openvstorage-sdm (1.6.7-rev.476.3674990-1) ...

Complete log:

2016-12-02 16:59:18 60100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 165 - INFO - 10.100.188.32  : Executing action: upgrade_alba_plugin
2016-12-02 16:59:18 97800 +0100 - e188-1 - 41618/140579817539392 - lib/update - 167 - INFO - 10.100.188.32  : Executing action: upgrade_sdm
2016-12-02 17:00:39 27100 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 171 - INFO - 10.100.188.32: Upgrading SDM
2016-12-02 17:00:59 37900 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 172 - WARNING - Attempt 1 to update SDM failed, trying again
2016-12-02 17:01:11 79200 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 173 - WARNING - Attempt 2 to update SDM failed, trying again
2016-12-02 17:01:41 94800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 174 - WARNING - Attempt 3 to update SDM failed, trying again
2016-12-02 17:02:12 09200 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 175 - WARNING - Attempt 4 to update SDM failed, trying again
2016-12-02 17:02:42 23100 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 176 - WARNING - Attempt 5 to update SDM failed, trying again
2016-12-02 17:03:12 38800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 177 - WARNING - Attempt 6 to update SDM failed, trying again
2016-12-02 17:03:42 54400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 178 - WARNING - Attempt 7 to update SDM failed, trying again
2016-12-02 17:04:12 66700 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 179 - WARNING - Attempt 8 to update SDM failed, trying again
2016-12-02 17:04:42 82200 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 180 - WARNING - Attempt 9 to update SDM failed, trying again
2016-12-02 17:05:12 96900 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 181 - WARNING - Attempt 10 to update SDM failed, trying again
2016-12-02 17:05:43 12400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 182 - WARNING - Attempt 11 to update SDM failed, trying again
2016-12-02 17:06:13 27400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 183 - WARNING - Attempt 12 to update SDM failed, trying again
2016-12-02 17:06:13 27400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 184 - ERROR - 10.100.188.32: Error during update: HTTPSConnectionPool(host='10.100.188.32', port=8500): Read timed out. (read timeout=20)
2016-12-02 17:06:23 32400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 185 - ERROR - 10.100.188.32: Failed to perform SDM update. Please check the appropriate logfile on the node
2016-12-02 17:06:23 32400 +0100 - e188-1 - 41618/140579817539392 - lib/update - 186 - ERROR - 10.100.188.32  : Post upgrade action failed with error: Status after upgrade is "started"
2016-12-02 17:06:23 33700 +0100 - e188-1 - 41618/140579817539392 - lib/update - 187 - INFO - 10.100.188.31  : Executing action: restart_arakoon_clusters
2016-12-02 17:06:23 52300 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 188 - INFO - Restarting cluster be1-abm because of ALBA update
2016-12-02 17:06:28 60800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 240 - INFO - Restarting cluster be1-nsm_0 because of ALBA update
2016-12-02 17:06:33 66900 +0100 - e188-1 - 41618/140579817539392 - lib/update - 292 - INFO - 10.100.188.31  : Executing action: upgrade_alba_plugin
2016-12-02 17:06:33 67200 +0100 - e188-1 - 41618/140579817539392 - lib/update - 294 - INFO - 10.100.188.31  : Executing action: upgrade_sdm
2016-12-02 17:07:25 22600 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 298 - INFO - 10.100.188.31: Upgrading SDM
2016-12-02 17:08:00 85200 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 300 - WARNING - Attempt 2 to update SDM failed, trying again
2016-12-02 17:08:31 00400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 301 - WARNING - Attempt 3 to update SDM failed, trying again
2016-12-02 17:09:01 15600 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 302 - WARNING - Attempt 4 to update SDM failed, trying again
2016-12-02 17:09:31 28800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 303 - WARNING - Attempt 5 to update SDM failed, trying again
2016-12-02 17:10:01 44300 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 304 - WARNING - Attempt 6 to update SDM failed, trying again
2016-12-02 17:10:31 58300 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 305 - WARNING - Attempt 7 to update SDM failed, trying again
2016-12-02 17:11:01 73800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 306 - WARNING - Attempt 8 to update SDM failed, trying again
2016-12-02 17:11:31 84700 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 307 - WARNING - Attempt 9 to update SDM failed, trying again
2016-12-02 17:12:01 99000 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 308 - WARNING - Attempt 10 to update SDM failed, trying again
2016-12-02 17:12:32 14100 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 309 - WARNING - Attempt 11 to update SDM failed, trying again
2016-12-02 17:13:02 28800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 310 - WARNING - Attempt 12 to update SDM failed, trying again
2016-12-02 17:13:02 28800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 311 - ERROR - 10.100.188.31: Error during update: HTTPSConnectionPool(host='10.100.188.31', port=8500): Read timed out. (read timeout=20)
2016-12-02 17:13:12 33800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 312 - ERROR - 10.100.188.31: Failed to perform SDM update. Please check the appropriate logfile on the node
2016-12-02 17:13:12 33800 +0100 - e188-1 - 41618/140579817539392 - lib/update - 313 - ERROR - 10.100.188.31  : Post upgrade action failed with error: Status after upgrade is "running"
2016-12-02 17:13:12 34500 +0100 - e188-1 - 41618/140579817539392 - lib/update - 314 - INFO - 10.100.188.33  : Executing action: restart_arakoon_clusters
2016-12-02 17:13:13 18000 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 315 - INFO - Restarting cluster be1-abm because of ALBA update
2016-12-02 17:13:18 75900 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 381 - INFO - Restarting cluster be1-nsm_0 because of ALBA update
2016-12-02 17:13:24 27700 +0100 - e188-1 - 41618/140579817539392 - lib/update - 429 - INFO - 10.100.188.33  : Executing action: upgrade_alba_plugin
2016-12-02 17:13:24 64300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 431 - INFO - 10.100.188.33  : Executing action: upgrade_sdm
2016-12-02 17:14:09 15000 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 435 - INFO - 10.100.188.33: Upgrading SDM
2016-12-02 17:14:49 40600 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 438 - WARNING - Attempt 3 to update SDM failed, trying again
2016-12-02 17:15:19 52800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 439 - WARNING - Attempt 4 to update SDM failed, trying again
2016-12-02 17:15:49 67700 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 440 - WARNING - Attempt 5 to update SDM failed, trying again
2016-12-02 17:16:19 80700 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 441 - WARNING - Attempt 6 to update SDM failed, trying again
2016-12-02 17:16:49 96000 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 442 - WARNING - Attempt 7 to update SDM failed, trying again
2016-12-02 17:17:20 10800 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 443 - WARNING - Attempt 8 to update SDM failed, trying again
2016-12-02 17:17:50 24600 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 444 - WARNING - Attempt 9 to update SDM failed, trying again
2016-12-02 17:18:20 38200 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 445 - WARNING - Attempt 10 to update SDM failed, trying again
2016-12-02 17:18:50 53200 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 446 - WARNING - Attempt 11 to update SDM failed, trying again
2016-12-02 17:19:20 67400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 447 - WARNING - Attempt 12 to update SDM failed, trying again
2016-12-02 17:19:20 67400 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 448 - ERROR - 10.100.188.33: Error during update: HTTPSConnectionPool(host='10.100.188.33', port=8500): Read timed out. (read timeout=20)
2016-12-02 17:19:30 72300 +0100 - e188-1 - 41618/140579817539392 - lib/alba - 449 - ERROR - 10.100.188.33: Failed to perform SDM update. Please check the appropriate logfile on the node
2016-12-02 17:19:30 72300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 450 - ERROR - 10.100.188.33  : Post upgrade action failed with error: Status after upgrade is "running"
2016-12-02 17:19:30 72400 +0100 - e188-1 - 41618/140579817539392 - lib/update - 451 - INFO - 10.100.188.31  : Starting services
2016-12-02 17:19:31 09500 +0100 - e188-1 - 41618/140579817539392 - lib/update - 452 - INFO - 10.100.188.32  : Starting service albaproxy_vp1
2016-12-02 17:19:31 34900 +0100 - e188-1 - 41618/140579817539392 - lib/update - 453 - DEBUG -   10.100.188.32   - Starting service albaproxy_vp1
2016-12-02 17:19:32 00300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 454 - DEBUG -   10.100.188.32   - Service albaproxy_vp1 started
2016-12-02 17:19:32 00300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 455 - INFO - 10.100.188.32  : Started service albaproxy_vp1
2016-12-02 17:19:32 00400 +0100 - e188-1 - 41618/140579817539392 - lib/update - 456 - INFO - 10.100.188.31  : Starting service albaproxy_vp1
2016-12-02 17:19:32 01900 +0100 - e188-1 - 41618/140579817539392 - lib/update - 457 - DEBUG -   10.100.188.31   - Starting service albaproxy_vp1
2016-12-02 17:19:32 09100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 458 - DEBUG -   10.100.188.31   - Service albaproxy_vp1 started
2016-12-02 17:19:32 09100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 459 - INFO - 10.100.188.31  : Started service albaproxy_vp1
2016-12-02 17:19:32 21800 +0100 - e188-1 - 41618/140579817539392 - lib/update - 460 - INFO - 10.100.188.33  : Starting service albaproxy_vp1
2016-12-02 17:19:32 47600 +0100 - e188-1 - 41618/140579817539392 - lib/update - 461 - DEBUG -   10.100.188.33   - Starting service albaproxy_vp1
2016-12-02 17:19:33 16300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 462 - DEBUG -   10.100.188.33   - Service albaproxy_vp1 started
2016-12-02 17:19:33 16300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 463 - INFO - 10.100.188.33  : Started service albaproxy_vp1
2016-12-02 17:19:33 18500 +0100 - e188-1 - 41618/140579817539392 - lib/update - 464 - INFO - 10.100.188.32  : Starting service ovs-dtl_vp1
2016-12-02 17:19:33 32100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 465 - DEBUG -   10.100.188.32   - Starting service ovs-dtl_vp1
2016-12-02 17:19:33 69100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 466 - DEBUG -   10.100.188.32   - Service ovs-dtl_vp1 started
2016-12-02 17:19:33 69100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 467 - INFO - 10.100.188.32  : Started service ovs-dtl_vp1
2016-12-02 17:19:33 69200 +0100 - e188-1 - 41618/140579817539392 - lib/update - 468 - INFO - 10.100.188.31  : Starting service ovs-dtl_vp1
2016-12-02 17:19:33 70600 +0100 - e188-1 - 41618/140579817539392 - lib/update - 469 - DEBUG -   10.100.188.31   - Starting service ovs-dtl_vp1
2016-12-02 17:19:33 75500 +0100 - e188-1 - 41618/140579817539392 - lib/update - 470 - DEBUG -   10.100.188.31   - Service ovs-dtl_vp1 started
2016-12-02 17:19:33 75600 +0100 - e188-1 - 41618/140579817539392 - lib/update - 471 - INFO - 10.100.188.31  : Started service ovs-dtl_vp1
2016-12-02 17:19:33 78400 +0100 - e188-1 - 41618/140579817539392 - lib/update - 472 - INFO - 10.100.188.33  : Starting service ovs-dtl_vp1
2016-12-02 17:19:33 89200 +0100 - e188-1 - 41618/140579817539392 - lib/update - 473 - DEBUG -   10.100.188.33   - Starting service ovs-dtl_vp1
2016-12-02 17:19:34 28700 +0100 - e188-1 - 41618/140579817539392 - lib/update - 474 - DEBUG -   10.100.188.33   - Service ovs-dtl_vp1 started
2016-12-02 17:19:34 28700 +0100 - e188-1 - 41618/140579817539392 - lib/update - 475 - INFO - 10.100.188.33  : Started service ovs-dtl_vp1
2016-12-02 17:19:34 31100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 476 - INFO - 10.100.188.32  : Starting service ovs-volumedriver_vp1
2016-12-02 17:19:34 44600 +0100 - e188-1 - 41618/140579817539392 - lib/update - 477 - DEBUG -   10.100.188.32   - Starting service ovs-volumedriver_vp1
2016-12-02 17:19:34 83800 +0100 - e188-1 - 41618/140579817539392 - lib/update - 478 - DEBUG -   10.100.188.32   - Service ovs-volumedriver_vp1 started
2016-12-02 17:19:34 83800 +0100 - e188-1 - 41618/140579817539392 - lib/update - 479 - INFO - 10.100.188.32  : Started service ovs-volumedriver_vp1
2016-12-02 17:19:34 83900 +0100 - e188-1 - 41618/140579817539392 - lib/update - 480 - INFO - 10.100.188.31  : Starting service ovs-volumedriver_vp1
2016-12-02 17:19:34 85300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 481 - DEBUG -   10.100.188.31   - Starting service ovs-volumedriver_vp1
2016-12-02 17:19:34 90200 +0100 - e188-1 - 41618/140579817539392 - lib/update - 482 - DEBUG -   10.100.188.31   - Service ovs-volumedriver_vp1 started
2016-12-02 17:19:34 90300 +0100 - e188-1 - 41618/140579817539392 - lib/update - 483 - INFO - 10.100.188.31  : Started service ovs-volumedriver_vp1
2016-12-02 17:19:34 92600 +0100 - e188-1 - 41618/140579817539392 - lib/update - 484 - INFO - 10.100.188.33  : Starting service ovs-volumedriver_vp1
2016-12-02 17:19:35 03600 +0100 - e188-1 - 41618/140579817539392 - lib/update - 485 - DEBUG -   10.100.188.33   - Starting service ovs-volumedriver_vp1
2016-12-02 17:19:35 40000 +0100 - e188-1 - 41618/140579817539392 - lib/update - 486 - DEBUG -   10.100.188.33   - Service ovs-volumedriver_vp1 started
2016-12-02 17:19:35 40100 +0100 - e188-1 - 41618/140579817539392 - lib/update - 487 - INFO - 10.100.188.33  : Started service ovs-volumedriver_vp1
2016-12-02 17:19:35 67200 +0100 - e188-1 - 41618/140579817539392 - lib/update - 488 - INFO - +++ Finished updating +++

FRAMEWORK UPDATE

2016-12-02 17:31:05 97000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 0 - INFO - +++ Starting framework update +++
2016-12-02 17:31:06 01100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 1 - INFO - Generating SSH client connections for each storage router
2016-12-02 17:31:06 40600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 2 - INFO - 10.100.188.31  : Creating lock files
2016-12-02 17:31:06 63100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 3 - INFO - 10.100.188.32  : Executing function get_metadata_alba
2016-12-02 17:31:07 18700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 4 - INFO - 10.100.188.32  : Executing function get_metadata_sdm
2016-12-02 17:31:28 93100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 6 - INFO - 10.100.188.32  : Executing function get_metadata_framework
2016-12-02 17:31:29 48300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 7 - INFO - 10.100.188.32  : Executing function get_metadata_volumedriver
2016-12-02 17:31:30 27800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 8 - INFO - 10.100.188.31  : Executing function get_metadata_alba
2016-12-02 17:31:30 36700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 9 - INFO - 10.100.188.31  : Executing function get_metadata_sdm
2016-12-02 17:31:51 86700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 11 - INFO - 10.100.188.31  : Executing function get_metadata_framework
2016-12-02 17:31:52 02800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 12 - INFO - 10.100.188.31  : Executing function get_metadata_volumedriver
2016-12-02 17:31:52 20000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 13 - INFO - 10.100.188.33  : Executing function get_metadata_alba
2016-12-02 17:31:52 74500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 14 - INFO - 10.100.188.33  : Executing function get_metadata_sdm
2016-12-02 17:32:14 46100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 16 - INFO - 10.100.188.33  : Executing function get_metadata_framework
2016-12-02 17:32:15 00700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 17 - INFO - 10.100.188.33  : Executing function get_metadata_volumedriver
2016-12-02 17:32:15 79000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 18 - INFO - Services which will be restarted --> watcher-framework, memcached
2016-12-02 17:32:15 79100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 19 - INFO - Packages which will be installed --> openvstorage-core, openvstorage-backend-core, openvstorage-webapps, openvstorage-backend-webapps
2016-12-02 17:32:15 96800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 20 - INFO - 10.100.188.32  : Stopping service watcher-framework
2016-12-02 17:32:16 24500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 21 - DEBUG -   10.100.188.32   - Stopping service watcher-framework
2016-12-02 17:32:17 51800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 22 - DEBUG -   10.100.188.32   - Service watcher-framework stopped
2016-12-02 17:32:17 51900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 23 - INFO - 10.100.188.32  : Stopped service watcher-framework
2016-12-02 17:32:17 51900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 24 - INFO - 10.100.188.31  : Stopping service watcher-framework
2016-12-02 17:32:17 53400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 25 - DEBUG -   10.100.188.31   - Stopping service watcher-framework
2016-12-02 17:32:18 15400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 26 - DEBUG -   10.100.188.31   - Service watcher-framework stopped
2016-12-02 17:32:18 15400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 27 - INFO - 10.100.188.31  : Stopped service watcher-framework
2016-12-02 17:32:18 29300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 28 - INFO - 10.100.188.33  : Stopping service watcher-framework
2016-12-02 17:32:18 60100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 29 - DEBUG -   10.100.188.33   - Stopping service watcher-framework
2016-12-02 17:32:20 81200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 30 - DEBUG -   10.100.188.33   - Service watcher-framework stopped
2016-12-02 17:32:20 81200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 31 - INFO - 10.100.188.33  : Stopped service watcher-framework
2016-12-02 17:32:20 89400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 32 - INFO - 10.100.188.32  : Stopping service memcached
2016-12-02 17:32:21 09600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 33 - DEBUG -   10.100.188.32   - Stopping service memcached
2016-12-02 17:32:21 72400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 34 - DEBUG -   10.100.188.32   - Service memcached stopped
2016-12-02 17:32:21 72500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 35 - INFO - 10.100.188.32  : Stopped service memcached
2016-12-02 17:32:21 72500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 36 - INFO - 10.100.188.31  : Stopping service memcached
2016-12-02 17:32:21 74400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 37 - DEBUG -   10.100.188.31   - Stopping service memcached
2016-12-02 17:32:21 79600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 38 - DEBUG -   10.100.188.31   - Service memcached stopped
2016-12-02 17:32:21 79600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 39 - INFO - 10.100.188.31  : Stopped service memcached
2016-12-02 17:32:21 90600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 40 - INFO - 10.100.188.33  : Stopping service memcached
2016-12-02 17:32:22 10800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 41 - DEBUG -   10.100.188.33   - Stopping service memcached
2016-12-02 17:32:22 65700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 42 - DEBUG -   10.100.188.33   - Service memcached stopped
2016-12-02 17:32:22 65800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 43 - INFO - 10.100.188.33  : Stopped service memcached
2016-12-02 17:32:51 41700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 44 - INFO - 10.100.188.32  : Installing latest packages
2016-12-02 17:32:51 41800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 45 - INFO - 10.100.188.32  : Installing openvstorage-core
2016-12-02 17:32:59 20200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 46 - INFO - 10.100.188.32  : Installed openvstorage-core
2016-12-02 17:32:59 20200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 47 - INFO - 10.100.188.32  : Installing openvstorage-backend-core
2016-12-02 17:33:05 34900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 48 - INFO - 10.100.188.32  : Installed openvstorage-backend-core
2016-12-02 17:33:05 34900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 49 - INFO - 10.100.188.32  : Installing openvstorage-webapps
2016-12-02 17:33:05 90300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 50 - INFO - 10.100.188.32  : Installed openvstorage-webapps
2016-12-02 17:33:05 90400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 51 - INFO - 10.100.188.32  : Installing openvstorage-backend-webapps
2016-12-02 17:33:06 48200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 52 - INFO - 10.100.188.32  : Installed openvstorage-backend-webapps
2016-12-02 17:33:36 55400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 53 - INFO - 10.100.188.31  : Installing latest packages
2016-12-02 17:33:36 55400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 54 - INFO - 10.100.188.31  : Installing openvstorage-core
2016-12-02 17:33:44 06500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 55 - INFO - 10.100.188.31  : Installed openvstorage-core
2016-12-02 17:33:44 06500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 56 - INFO - 10.100.188.31  : Installing openvstorage-backend-core
2016-12-02 17:33:50 00000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 57 - INFO - 10.100.188.31  : Installed openvstorage-backend-core
2016-12-02 17:33:50 00100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 58 - INFO - 10.100.188.31  : Installing openvstorage-webapps
2016-12-02 17:33:50 46400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 59 - INFO - 10.100.188.31  : Installed openvstorage-webapps
2016-12-02 17:33:50 46500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 60 - INFO - 10.100.188.31  : Installing openvstorage-backend-webapps
2016-12-02 17:33:50 95900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 61 - INFO - 10.100.188.31  : Installed openvstorage-backend-webapps
2016-12-02 17:34:12 87200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 62 - INFO - 10.100.188.33  : Installing latest packages
2016-12-02 17:34:12 87200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 63 - INFO - 10.100.188.33  : Installing openvstorage-core
2016-12-02 17:34:20 39200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 64 - INFO - 10.100.188.33  : Installed openvstorage-core
2016-12-02 17:34:20 39200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 65 - INFO - 10.100.188.33  : Installing openvstorage-backend-core
2016-12-02 17:34:26 55200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 66 - INFO - 10.100.188.33  : Installed openvstorage-backend-core
2016-12-02 17:34:26 55300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 67 - INFO - 10.100.188.33  : Installing openvstorage-webapps
2016-12-02 17:34:27 15700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 68 - INFO - 10.100.188.33  : Installed openvstorage-webapps
2016-12-02 17:34:27 15800 +0100 - e188-1 - 51900/139786279216960 - lib/update - 69 - INFO - 10.100.188.33  : Installing openvstorage-backend-webapps
2016-12-02 17:34:27 74000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 70 - INFO - 10.100.188.33  : Installed openvstorage-backend-webapps
2016-12-02 17:34:27 84500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 71 - INFO - 10.100.188.32  : Started code migration
2016-12-02 17:34:28 92600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 72 - INFO - 10.100.188.32  : Finished code migration
2016-12-02 17:34:28 92600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 73 - INFO - 10.100.188.31  : Started code migration
2016-12-02 17:34:30 00400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 74 - INFO - 10.100.188.31  : Finished code migration
2016-12-02 17:34:30 00400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 75 - INFO - 10.100.188.33  : Started code migration
2016-12-02 17:34:31 12500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 76 - INFO - 10.100.188.33  : Finished code migration
2016-12-02 17:34:31 12500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 77 - INFO - 10.100.188.31  : Starting services
2016-12-02 17:34:31 20700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 78 - INFO - 10.100.188.32  : Starting service memcached
2016-12-02 17:34:31 40700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 79 - DEBUG -   10.100.188.32   - Starting service memcached
2016-12-02 17:34:32 01600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 80 - DEBUG -   10.100.188.32   - Service memcached started
2016-12-02 17:34:32 01700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 81 - INFO - 10.100.188.32  : Started service memcached
2016-12-02 17:34:32 01700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 82 - INFO - 10.100.188.31  : Starting service memcached
2016-12-02 17:34:32 03500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 83 - DEBUG -   10.100.188.31   - Starting service memcached
2016-12-02 17:34:32 10500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 84 - DEBUG -   10.100.188.31   - Service memcached started
2016-12-02 17:34:32 10500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 85 - INFO - 10.100.188.31  : Started service memcached
2016-12-02 17:34:32 18100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 86 - INFO - 10.100.188.33  : Starting service memcached
2016-12-02 17:34:32 40100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 87 - DEBUG -   10.100.188.33   - Starting service memcached
2016-12-02 17:34:32 99200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 88 - DEBUG -   10.100.188.33   - Service memcached started
2016-12-02 17:34:32 99300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 89 - INFO - 10.100.188.33  : Started service memcached
2016-12-02 17:34:32 99300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 90 - INFO - 10.100.188.31  : Started model migration
2016-12-02 17:34:34 26500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 91 - INFO - 10.100.188.31  : Finished model migration
2016-12-02 17:34:34 26500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 92 - INFO - 10.100.188.31  : Executing post upgrade actions
2016-12-02 17:34:38 55900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 93 - INFO - 10.100.188.32  : Starting service watcher-framework
2016-12-02 17:34:38 84300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 94 - DEBUG -   10.100.188.32   - Starting service watcher-framework
2016-12-02 17:34:39 76500 +0100 - e188-1 - 51900/139786279216960 - lib/update - 95 - DEBUG -   10.100.188.32   - Service watcher-framework started
2016-12-02 17:34:39 76600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 96 - INFO - 10.100.188.32  : Started service watcher-framework
2016-12-02 17:34:39 76600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 97 - INFO - 10.100.188.31  : Starting service watcher-framework
2016-12-02 17:34:39 78000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 98 - DEBUG -   10.100.188.31   - Starting service watcher-framework
2016-12-02 17:34:40 23200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 99 - DEBUG -   10.100.188.31   - Service watcher-framework started
2016-12-02 17:34:40 23200 +0100 - e188-1 - 51900/139786279216960 - lib/update - 100 - INFO - 10.100.188.31  : Started service watcher-framework
2016-12-02 17:34:40 39000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 101 - INFO - 10.100.188.33  : Starting service watcher-framework
2016-12-02 17:34:40 68700 +0100 - e188-1 - 51900/139786279216960 - lib/update - 102 - DEBUG -   10.100.188.33   - Starting service watcher-framework
2016-12-02 17:34:41 62000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 103 - DEBUG -   10.100.188.33   - Service watcher-framework started
2016-12-02 17:34:41 62100 +0100 - e188-1 - 51900/139786279216960 - lib/update - 104 - INFO - 10.100.188.33  : Started service watcher-framework
2016-12-02 17:34:41 74600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 105 - INFO - 10.100.188.32  : Restarting service support-agent
2016-12-02 17:34:41 96300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 106 - DEBUG -   10.100.188.32   - Restarting service support-agent
2016-12-02 17:34:43 24300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 107 - DEBUG -   10.100.188.32   - Service support-agent restarted
2016-12-02 17:34:43 24400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 108 - INFO - 10.100.188.32  : Restarted service support-agent
2016-12-02 17:34:43 24400 +0100 - e188-1 - 51900/139786279216960 - lib/update - 109 - INFO - 10.100.188.31  : Restarting service support-agent
2016-12-02 17:34:43 25900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 110 - DEBUG -   10.100.188.31   - Restarting service support-agent
2016-12-02 17:34:43 33600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 111 - DEBUG -   10.100.188.31   - Service support-agent restarted
2016-12-02 17:34:43 33600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 112 - INFO - 10.100.188.31  : Restarted service support-agent
2016-12-02 17:34:43 51900 +0100 - e188-1 - 51900/139786279216960 - lib/update - 113 - INFO - 10.100.188.33  : Restarting service support-agent
2016-12-02 17:34:43 79600 +0100 - e188-1 - 51900/139786279216960 - lib/update - 114 - DEBUG -   10.100.188.33   - Restarting service support-agent
2016-12-02 17:34:45 11300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 115 - DEBUG -   10.100.188.33   - Service support-agent restarted
2016-12-02 17:34:45 11300 +0100 - e188-1 - 51900/139786279216960 - lib/update - 116 - INFO - 10.100.188.33  : Restarted service support-agent
2016-12-02 17:34:45 38000 +0100 - e188-1 - 51900/139786279216960 - lib/update - 117 - INFO - +++ Finished updating +++
khenderick commented 7 years ago

This is the old update logic, can you re-test on new logic?

kvanhijf commented 7 years ago

Update did actually succeed in above scenario, however when such error occurs the following actions should be done to ensure a proper working environment: 1) Verify ALBA package is latest and greatest (apt-cache policy alba) 2) Verify openvstorage-sdm package is latest and greatest (apt-cache policy openvstorage-sdm) 3) When 1) and 2) are met, restart all services

from ovs.dal.lists.albanodelist import AlbaNodeList
for node in AlbaNodeList.get_albanodes():
    node.client.restart_services()

4) Profit!

kvanhijf commented 7 years ago

A manual patch could also be applied to prevent the SDM package update to fail Execute code below for this:

vi /opt/OpenvStorage/ovs/extensions/plugins/asdmanager.py +210

Replace

return self._call(requests.post, 'update/execute/{0}'.format(status))

with

return self._call(requests.post, 'update/execute/{0}'.format(status), timeout=300)