Red Hat Bugzilla – Bug 1346852
[GUI] Bad Request when resource removal takes longer than pcs expects
Last modified: 2016-11-03 16:58:59 EDT
> Description of problem: Removing resources that tend to stop longer than usual or a larger number of them sometimes leads to an unexpected "Unable to remove resources (Bad Request)" error. The error seems to be caused by the fact that while the GUI waits for a relatively short time before a request times out on first node and sends the same request to another node, it will eventually finish on the first node, leaving the other node with no resources to remove. The logs below are taken from a setup where virt-121 is a remote GUI machine, virt-123 and virt-127 are cluster nodes. The request for deletion of 17 resources at once is sent to virt-123 however as it doesn't return within a 30 seconds window, it is resent to virt-127. In the meantime the resources have been deleted on virt-123 leading to errors in the response from virt-127. > Version-Release number of selected component (if applicable): pcs-0.9.151-2.el7.x86_64 > How reproducible: Frequently with resources to be stopped slow enough > Steps to Reproduce: 1. Create a bunch of resources or use a specific resource with delay option 2. Remove these resources all at once using the GUI 3. Wait for it... > Actual results: Often, "Unable to remove resources (Bad Request)" although the resources are in fact removed. > Expected results: No GUI error if resources are really removed. > Logs virt-121 (GUI node) https://virt-121:2224/managec/STSRHTS29046/main -> /favicon.ico I, [2016-06-14T15:57:57.675435 #934] INFO -- : Running: id -Gn hacluster I, [2016-06-14T15:57:57.675554 #934] INFO -- : CIB USER: hacluster, groups: I, [2016-06-14T15:57:57.682401 #934] INFO -- : Return Value: 0 I, [2016-06-14T15:57:57.682548 #934] INFO -- : Running: id -Gn hacluster I, [2016-06-14T15:57:57.682595 #934] INFO -- : CIB USER: hacluster, groups: I, [2016-06-14T15:57:57.688376 #934] INFO -- : Return Value: 0 I, [2016-06-14T15:57:57.688537 #934] INFO -- : Running: /usr/sbin/corosync-cmapctl totem.cluster_name I, [2016-06-14T15:57:57.688587 #934] INFO -- : CIB USER: hacluster, groups: I, [2016-06-14T15:57:57.693915 #934] INFO -- : Return Value: 1 W, [2016-06-14T15:57:57.694066 #934] WARN -- : Cannot read config 'corosync.conf' from '/etc/corosync/corosync.conf': No such file W, [2016-06-14T15:57:57.694173 #934] WARN -- : Cannot read config 'corosync.conf' from '/etc/corosync/corosync.conf': No such file or directory - /etc/corosync/corosync.conf I, [2016-06-14T15:57:57.694668 #934] INFO -- : SCRWT: /remove_resource I, [2016-06-14T15:57:57.694939 #934] INFO -- : SNRWT: /remove_resource I, [2016-06-14T15:57:57.694981 #934] INFO -- : SNRWT Node: virt-123 Request: /remove_resource I, [2016-06-14T15:57:57.695126 #934] INFO -- : SRWT Node: virt-123 Request: /remove_resource I, [2016-06-14T15:58:00.802062 #934] INFO -- : Running: /usr/sbin/corosync-cmapctl totem.cluster_name I, [2016-06-14T15:58:00.802201 #934] INFO -- : CIB USER: hacluster, groups: I, [2016-06-14T15:58:00.808665 #934] INFO -- : Return Value: 1 W, [2016-06-14T15:58:00.808799 #934] WARN -- : Cannot read config 'corosync.conf' from '/etc/corosync/corosync.conf': No such file W, [2016-06-14T15:58:00.808860 #934] WARN -- : Cannot read config 'corosync.conf' from '/etc/corosync/corosync.conf': No such file or directory - /etc/corosync/corosync.conf I, [2016-06-14T15:58:27.720224 #934] INFO -- : No response from: virt-123 request: /remove_resource, exception: Net::ReadTimeout I, [2016-06-14T15:58:27.720443 #934] INFO -- : SNRWT Node virt-123 Request /remove_resource: No response I, [2016-06-14T15:58:27.720483 #934] INFO -- : SNRWT Node: virt-127 Request: /remove_resource I, [2016-06-14T15:58:27.720744 #934] INFO -- : SRWT Node: virt-127 Request: /remove_resource I, [2016-06-14T15:58:48.624953 #934] INFO -- : SNRWT Node virt-127 Request /remove_resource: HTTP code 400 ::ffff:10.34.250.39 - - [14/Jun/2016:15:58:48 +0200] "POST /managec/STSRHTS29046/remove_resource HTTP/1.1" 400 614 50.9510 ::ffff:10.34.250.39 - - [14/Jun/2016:15:58:48 +0200] "POST /managec/STSRHTS29046/remove_resource HTTP/1.1" 400 614 50.9511 ::ffff:10.34.250.39 - - [14/Jun/2016:15:57:57 CEST] "POST /managec/STSRHTS29046/remove_resource HTTP/1.1" 400 614 https://virt-121:2224/managec/STSRHTS29046/main -> /managec/STSRHTS29046/remove_resource > Logs virt-123 (cluster node) I, [2016-06-14T15:57:57.756854 #20396] INFO -- : Running: /usr/sbin/corosync-cmapctl totem.cluster_name I, [2016-06-14T15:57:57.756968 #20396] INFO -- : CIB USER: hacluster, groups: I, [2016-06-14T15:57:57.773873 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:57:57.841133 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy4 I, [2016-06-14T15:57:57.841282 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:01.090293 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:01.090565 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy5 I, [2016-06-14T15:58:01.090634 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:04.301256 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:04.301560 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy6 I, [2016-06-14T15:58:04.301632 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:07.458319 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:07.458603 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy7 I, [2016-06-14T15:58:07.458669 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:10.537067 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:10.537389 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy8 I, [2016-06-14T15:58:10.537538 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:13.469148 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:13.469363 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy9 I, [2016-06-14T15:58:13.469430 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:16.322712 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:16.323012 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummya I, [2016-06-14T15:58:16.323090 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:19.155789 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:19.156016 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummyb I, [2016-06-14T15:58:19.156149 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:21.979330 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:21.979585 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummyc I, [2016-06-14T15:58:21.979641 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:24.800763 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:24.801077 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummyd I, [2016-06-14T15:58:24.801143 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:27.536076 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:27.536317 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummye I, [2016-06-14T15:58:27.536376 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:30.308060 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:30.308365 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummyf I, [2016-06-14T15:58:30.308438 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:32.992911 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:32.993171 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummyg I, [2016-06-14T15:58:32.993330 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:35.641956 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:35.642196 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummyh I, [2016-06-14T15:58:35.642257 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:38.283506 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:38.283816 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy1 I, [2016-06-14T15:58:38.283881 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:40.877220 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:40.877449 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy2 I, [2016-06-14T15:58:40.877555 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:45.637007 #20396] INFO -- : Return Value: 0 I, [2016-06-14T15:58:45.637259 #20396] INFO -- : Running: /usr/sbin/pcs resource delete dummy3 I, [2016-06-14T15:58:45.637335 #20396] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:48.607989 #20396] INFO -- : Return Value: 0 ::ffff:10.34.70.248 - - [14/Jun/2016:15:58:48 +0200] "POST /remote/remove_resource HTTP/1.1" 200 - 50.8532 ::ffff:10.34.70.248 - - [14/Jun/2016:15:58:48 +0200] "POST /remote/remove_resource HTTP/1.1" 200 - 50.8534 virt-121 - - [14/Jun/2016:15:57:57 CEST] "POST /remote/remove_resource HTTP/1.1" 200 0 - -> /remote/remove_resource > Logs virt-127 (cluster node) I, [2016-06-14T15:58:27.784831 #3658] INFO -- : Running: /usr/sbin/corosync-cmapctl totem.cluster_name I, [2016-06-14T15:58:27.784963 #3658] INFO -- : CIB USER: hacluster, groups: I, [2016-06-14T15:58:27.801420 #3658] INFO -- : Return Value: 0 I, [2016-06-14T15:58:27.867097 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy4 I, [2016-06-14T15:58:27.867252 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:28.897271 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:28.897786 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy5 I, [2016-06-14T15:58:28.897850 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:29.943949 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:29.944204 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy6 I, [2016-06-14T15:58:29.944270 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:31.084769 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:31.085019 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy7 I, [2016-06-14T15:58:31.085088 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:32.141195 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:32.141639 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy8 I, [2016-06-14T15:58:32.141721 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:33.306319 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:33.306608 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy9 I, [2016-06-14T15:58:33.306676 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:34.343596 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:34.343901 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummya I, [2016-06-14T15:58:34.343969 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:35.361929 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:35.362303 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummyb I, [2016-06-14T15:58:35.362378 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:36.448603 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:36.448862 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummyc I, [2016-06-14T15:58:36.448936 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:37.455932 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:37.456202 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummyd I, [2016-06-14T15:58:37.456267 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:38.556152 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:38.556592 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummye I, [2016-06-14T15:58:38.556657 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:39.547307 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:39.547617 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummyf I, [2016-06-14T15:58:39.547690 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:40.581176 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:40.581485 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummyg I, [2016-06-14T15:58:40.581556 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:41.664848 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:41.665223 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummyh I, [2016-06-14T15:58:41.665282 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:42.672358 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:42.672684 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy1 I, [2016-06-14T15:58:42.672764 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:43.646884 #3658] INFO -- : Return Value: 1 I, [2016-06-14T15:58:43.647152 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy2 I, [2016-06-14T15:58:43.647224 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:45.627051 #3658] INFO -- : Return Value: 0 I, [2016-06-14T15:58:45.627321 #3658] INFO -- : Running: /usr/sbin/pcs resource delete dummy3 I, [2016-06-14T15:58:45.627385 #3658] INFO -- : CIB USER: hacluster, groups: haclient I, [2016-06-14T15:58:48.590666 #3658] INFO -- : Return Value: 0 I, [2016-06-14T15:58:48.590905 #3658] INFO -- : Remove resource errors: Error: Resource 'dummy4' does not exist. Error: Resource 'dummy5' does not exist. Error: Resource 'dummy6' does not exist. Error: Resource 'dummy7' does not exist. Error: Resource 'dummy8' does not exist. Error: Resource 'dummy9' does not exist. Error: Resource 'dummya' does not exist. Error: Resource 'dummyb' does not exist. Error: Resource 'dummyc' does not exist. Error: Resource 'dummyd' does not exist. Error: Resource 'dummye' does not exist. Error: Resource 'dummyf' does not exist. Error: Resource 'dummyg' does not exist. Error: Resource 'dummyh' does not exist. Error: Resource 'dummy1' does not exist. ::ffff:10.34.70.248 - - [14/Jun/2016:15:58:48 +0200] "POST /remote/remove_resource HTTP/1.1" 400 614 20.8079 ::ffff:10.34.70.248 - - [14/Jun/2016:15:58:48 +0200] "POST /remote/remove_resource HTTP/1.1" 400 614 20.8081 virt-121 - - [14/Jun/2016:15:58:27 CEST] "POST /remote/remove_resource HTTP/1.1" 400 614 - -> /remote/remove_resource
proposed fixes: https://github.com/ClusterLabs/pcs/commit/e00fd8f634a49562c96d08afb043c175ee https://github.com/ClusterLabs/pcs/commit/9321b5b9e94b3d532400ff8e2bee2db5c6 Test: Create few resources with longer stopping time. > [root@rhel7-node1 ~]# for i in {1..10}; do pcs resource create dummy$i ocf:pacemaker:Dummy op_sleep=5; done Wait until all of them will start up. Then in GUI delete these resource at once. Resources will be removed and no error message will be displayed.
Before fix: [vm-rhel72-1 ~] $ rpm -q pcs pcs-0.9.151-1.el7.x86_64 [vm-rhel72-1 ~] $ for i in {1..10}; do pcs resource create dummy$i ocf:pacemaker:Dummy op_sleep=5; done Wait until all of them will start up. In web UI delete created resource at once. Error message appear: """ Unable to remove resources (Bad Request) Error: Resource 'dummy1' does not exist. Error: Resource 'dummy10' does not exist. Error: Resource 'dummy2' does not exist. Error: Resource 'dummy3' does not exist. Error: Resource 'dummy4' does not exist. Error: Resource 'dummy5' does not exist. Error: Resource 'dummy6' does not exist. Error: Resource 'dummy7' does not exist. """ After fix: [vm-rhel72-1 ~] $ rpm -q pcs pcs-0.9.152-3.el7.x86_64 [vm-rhel72-1 ~] $ for i in {1..10}; do pcs resource create dummy$i ocf:pacemaker:Dummy op_sleep=5; done Wait until all of them will start up. Resources will be removed and no error message will be displayed.
additional fixes: https://github.com/ClusterLabs/pcs/commit/174378be2c1dad08098e6bcca36278a95d0c https://github.com/ClusterLabs/pcs/commit/e7f7c63a0891f60f04f0db3dd30d53f03409 Test: Create few resources with longer stopping time. > [root@rhel7-node1 ~]# for i in {1..10}; do pcs resource create delay$i Delay startdelay=0 stopdelay=25 mondelay=0; done Wait until all of them will start up. Then in GUI delete these resource at once. Resources will be removed and no error message will be displayed. If removing resources takes longer than expected (timeout expired) user is notified by alert message.
Setup: Create few resources with longer stopping time. > [vm-rhel72-1 ~] $ for i in {1..10}; do pcs resource create delay$i Delay startdelay=0 stopdelay=25 mondelay=0; done Before Fix: [vm-rhel72-1 ~] $ rpm -q pcs pcs-0.9.152-4.el7.x86_64 Wait until all of them will start up. Then in GUI delete these resource at once. Error "Unable to remove resources (Bad Request)" appear. After Fix: [vm-rhel72-1 ~] $ rpm -q pcs pcs-0.9.152-5.el7.x86_64 Wait until all of them will start up. Then in GUI delete these resource at once. Resources will be removed and no error message will be displayed. If removing resources takes longer than expected (timeout expired) user is notified by alert message.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHSA-2016-2596.html