Unable to use data on a volume in a different host

aironfonteles commented 5 years ago

I have a scenario where Docker EE 18.09.1 is being used on top of Red Hat Enterprise Linux 7. HPE 3PAR Plugin was successfully installed and configured for Docker onto 5 RHEL 7 hosts.

After installation, HPE volumes can be successfully created using docker commands and the new volume is also available on all of the other hosts. The issue is after writing data to the hpe volume on one host, this data cant' be accessed from another host.

Specifically, there is a mySQL database that needs to be moved from one host to another (failover purposes), but when the mySQL database starts from the container, it doesn't have access to this data. Even though the volume is available on the other host. If the container is moved back to the original host, then the data is now available within the volume. Is there anything wrong with this configuration?

I found the following under limitations: “Shared volume support is present for containers running on the same host.” https://github.com/hpe-storage/python-hpedockerplugin/blob/master/README.md#limitations

Is the above statement accurate? Is there any other way to get the functionality this customer is looking for?

Thanks in advance for all your help!

wdurairaj commented 5 years ago

@aironfonteles, can you give us exact steps (preferably with sample yaml files, container logs from individual nodes, kubectl commands etc.)

What version of the plugin are you running with ?

Container logs can be captured using docker logs <container_id_of_plugin> where the <container_id_of_plugin> can be got by docker ps -a | grep hpe

prablr79 commented 5 years ago

@aironfonteles any update on this bug ? did you get a chance talk to the customer get some logs for us ?

aironfonteles commented 5 years ago

1 - can you provide exact steps (preferably with sample yaml files, container logs from individual nodes, etc.)

This yaml file is deployed as a “stack” in swarm via UCP UI. Here is the yaml file. `version: '3' services: mysql: image: mysql:5.6 environment:

MYSQL_ROOT_PASSWORD=some pass volumes:
Docker-Vol-02:/var/lib/mysql deploy: replicas: 1 restart_policy: condition: on-failure networks:
ipamnet ipam: depends_on:
mysql image: dtr.srv.fortlewis.edu/systems/phpipam:1.1 environment:
MYSQL_ENV_MYSQL_USER=root
MYSQL_ENV_MYSQL_ROOT_PASSWORD=some pass
MYSQL_ENV_MYSQL_HOST=mysql ports:
"20003:80" networks:
ipamnet deploy: replicas: 1 restart_policy: condition: on-failure volumes: Docker-Vol-02: external: true networks: ipamnet:`

As you can see I am saying that this docker volume mounts to the /var/lib/mysql directory on the container for the mysql service. All 5 of our nodes, 3 manager, and 2 worker all have the HPE plugin enabled. Is the volume config in the yaml file correct? External: true ?

2 - What version of the plugin are you running with ? Version 3.0

3 - Please see the below info from the host after failover: [root@dockerm2 ~]# docker logs 09f89a7c6aca 2019-05-17 14:10:32 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2019-05-17 14:10:32 0 [Note] mysqld (mysqld 5.6.44) starting as process 1 ... 2019-05-17 14:10:32 1 [Note] Plugin 'FEDERATED' is disabled. 2019-05-17 14:10:32 1 [Note] InnoDB: Using atomics to ref count buffer pool pages 2019-05-17 14:10:32 1 [Note] InnoDB: The InnoDB memory heap is disabled 2019-05-17 14:10:32 1 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2019-05-17 14:10:32 1 [Note] InnoDB: Memory barrier is not used 2019-05-17 14:10:32 1 [Note] InnoDB: Compressed tables use zlib 1.2.11 2019-05-17 14:10:32 1 [Note] InnoDB: Using Linux native AIO 2019-05-17 14:10:32 1 [Note] InnoDB: Using CPU crc32 instructions 2019-05-17 14:10:32 1 [Note] InnoDB: Initializing buffer pool, size = 128.0M 2019-05-17 14:10:32 1 [Note] InnoDB: Completed initialization of buffer pool 2019-05-17 14:10:32 1 [Note] InnoDB: Highest supported file format is Barracuda. 2019-05-17 14:10:32 1 [Note] InnoDB: 128 rollback segment(s) are active. 2019-05-17 14:10:32 1 [Note] InnoDB: Waiting for purge to start 2019-05-17 14:10:32 1 [Note] InnoDB: 5.6.44 started; log sequence number 1626027 2019-05-17 14:10:32 1 [Note] Server hostname (bind-address): '*'; port: 3306 2019-05-17 14:10:32 1 [Note] IPv6 is available. 2019-05-17 14:10:32 1 [Note] - '::' resolves to '::'; 2019-05-17 14:10:32 1 [Note] Server socket created on IP: '::'. 2019-05-17 14:10:32 1 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory. 2019-05-17 14:10:32 1 [Warning] 'proxies_priv' entry '@ root@e3586723d653' ignored in --skip-name-resolve mode. 2019-05-17 14:10:32 1 [Note] Event Scheduler: Loaded 0 events 2019-05-17 14:10:32 1 [Note] mysqld: ready for connections. Version: '5.6.44' socket: '/var/run/mysqld/mysqld.sock' port: 3306 MySQL Community Server (GPL)

5- The command from host after failover: docker ps -a | grep hpe results in no results

One thing to note is the following: I have run separate containers based on alpine linux and simply mounted the hpe docker volume to the mysql directory. See this command:

docker container run -itd --name test-alpine --mount type=volume,source=Docker-Vol-02,target=/var/lib/mysql,volume-driver=hpe -d alpine:latest /bin/sh

And then, while browsing /var/lib/mysql . I do not see the correct mysql files. I do a touch.test file from the directory. But when I exec into the “production” container on original host, the touch.test file is not there. The problem does not appear to be with the container, but the lack of access to this data from different hosts. Even when the hpe plugin is enabled and “working”. I was going to try and create another volume and do some additional testing with this volume.

Also, our etcd is a cluster of 5 instances. In our hpe.conf file, we are pointing to a loadbalanced IP address that is pointing to all 5 etcd instances. I am not sure if that would be causing any issues. I know in the hpe.conf file that you can explicitily list all etcd IP addresses on one line, instead of the load balanced address.

On all 5 hosts, the command docker ps -a | grep hpe results in no results

And the funny thing is when, I restart the service to put it back on the original node where the data lives. The command above also returns no results.

So perhaps, the data is somehow on the local node, and not on the hpe plugin storage afterall ?

aironfonteles commented 5 years ago

The problem appears to be an issue with the volume itself.

Plugin updated to version 3.1 on all nodes (This did not solve the problem)
New volume named Docker-Vol-03 created with the following command: docker volume create -d hpe --name Docker-Vol-03 -o replicationGroup=BH-PP-RCG-Docker -o size=500 -o provisioning=thin
The new volume appears to be working “somewhat” as expected I am running the following command from each node to mount the volume and then write a test file. On each node, I verify that I can see the other servers test file docker container run -it --name test-alpine --mount type=volume,source=Docker-Vol-03,target=/var/lib/mysql,volume-driver=hpe:latest alpine:latest

Now what I am experiencing is that sometimes the volume is mounted right away, the container starts. Other times, I get a timeout when mounting the volume and the container does not start. I am also experiencing this bug as well : https://github.com/hpe-storage/python-hpedockerplugin/issues/517

My expectation is that this volume should be mounted and unmounted properly each time a container starts with that volume. I unfortunately am experiencing a bit of a reliability issue in regards to this expectation. I am going to deploy my iPAM stack with mysql server and see if I can properly fail this service over from one node to the other without loosing any data.

My secondary problem now is the fact that I cannot remove Docker-Vol-02 at all! I type “docker volume rm Docker-Vol-02” from each of my hosts and nothing ever happens. Is there a way that I can purge this volume?

aironfonteles commented 5 years ago

Hello @prablr79 Do you have any updates/feedback on this? Thanks in advance!

aironfonteles commented 5 years ago

Hi @prablr79 Customer is complaining about not being able to delete previously created volumes.

Any help will be greatly appreciated!

Thanks in advance!

prablr79 commented 5 years ago

@aironfonteles we are investigating this bug now, will sure revert with our observations.

prablr79 commented 5 years ago

@aironfonteles do you have setup which can be shared with us ? for investigation ? if yes can you share the details please ? send the details in mail address.

aironfonteles commented 5 years ago

@prablr79 Unfortunately, I don't have any test setup to share with you. Do you have any tips on what can we do in order to investigate why customer is not able to delete volumes? Thanks in advance!

aironfonteles commented 5 years ago

@prablr79

On messages file, I found the following errors:

Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil [-] Name: Docker-Vol-02 is already locked: etcd.EtcdAlreadyExist: Key already exists : /volumes-lock/Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil Traceback (most recent call last):" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil File \"/python-hpedockerplugin/hpedockerplugin/etcdutil.py\", line 188, in try_lock_name" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil prevExist=False)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 500, in write" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil response = self.api_execute(path, method, params=params)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 907, in wrapper" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil return self._handle_server_response(response)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 987, in _handle_server_response" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil etcd.EtcdError.handle(r)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/__init__.py\", line 306, in handle" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil raise exc(msg, payload)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil etcd.EtcdAlreadyExist: Key already exists : /volumes-lock/Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.630 20 ERROR hpedockerplugin.etcdutil \x1b[00m" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil [-] Key already exists : /volumes-lock/Docker-Vol-02: etcd.EtcdAlreadyExist: Key already exists : /volumes-lock/Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil Traceback (most recent call last):" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil File \"/python-hpedockerplugin/hpedockerplugin/etcdutil.py\", line 188, in try_lock_name" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil prevExist=False)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 500, in write" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil response = self.api_execute(path, method, params=params)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 907, in wrapper" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil return self._handle_server_response(response)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 987, in _handle_server_response" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil etcd.EtcdError.handle(r)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/__init__.py\", line 306, in handle" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil raise exc(msg, payload)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil etcd.EtcdAlreadyExist: Key already exists : /volumes-lock/Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.etcdutil \x1b[00m" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization [-] Lock acquire failed: [caller=remove_volume, lock-name=Docker-Vol-02]: hpedockerplugin.exception.HPEPluginLockFailed: ETCD lock failed: Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization Traceback (most recent call last):" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/python-hpedockerplugin/hpedockerplugin/etcdutil.py\", line 188, in try_lock_name" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization prevExist=False)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 500, in write" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization response = self.api_execute(path, method, params=params)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 907, in wrapper" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization return self._handle_server_response(response)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/client.py\", line 987, in _handle_server_response" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization etcd.EtcdError.handle(r)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/usr/lib/python3.6/site-packages/python_etcd-0.4.5-py3.6.egg/etcd/__init__.py\", line 306, in handle" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization raise exc(msg, payload)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization etcd.EtcdAlreadyExist: Key already exists : /volumes-lock/Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization " plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization During handling of the above exception, another exception occurred:" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization " plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization Traceback (most recent call last):" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/python-hpedockerplugin/hpedockerplugin/synchronization.py\", line 19, in __synchronized" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization lock.try_lock_name(lck_name)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization File \"/python-hpedockerplugin/hpedockerplugin/etcdutil.py\", line 194, in try_lock_name" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization raise exception.HPEPluginLockFailed(obj=name)" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization hpedockerplugin.exception.HPEPluginLockFailed: ETCD lock failed: Docker-Vol-02" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8 Jun 17 15:13:57 dockerw3 dockerd: time="2019-06-17T15:13:57-06:00" level=info msg="2019-06-17 21:13:57.631 20 ERROR hpedockerplugin.synchronization \x1b[00m" plugin=e415d041d13b331b944d8e2afba01a2de530bfa6e1773badb576bbe5c0cc83e8

Could you please take a look on the logs and provide any tips on how to fix it?

wdurairaj commented 5 years ago

We are investigating this issue, but wanted to quickly provide you a way to delete the volume stuck in deletion.

Do

$ docker volume inspect Docker-Vol-03
Take volume name in 3par_vol_name attribute, and in the connected 3PAR array
showvlun -v vol_name 4, removevlun -f for the LUN(s) involved in step 3
Now issue docker volume rm Docker-Vol-03

aironfonteles commented 5 years ago

Sorry it took me a few days. After running the commands you requested, the following occurred: There are no results of the following commands on both of my 3par arrays

3PAR-8400-BH1 cli% showvlun -v dcv-EdcLHR5hQfOMrw2ciFwt2A Active VLUNs no vluns listed

VLUN Templates no vluns listed 3PAR-8400-BH1 cli%

And

3PAR-8400-RL1 cli% showvlun -v dcv-EdcLHR5hQfOMrw2ciFwt2A.r Active VLUNs no vluns listed

VLUN Templates no vluns listed

Any other ideas?

aironfonteles commented 5 years ago

Any updates on this @wdurairaj ? Thanks!

nilangekarss commented 5 years ago

@aironfonteles Are you the person who has opened a bugzilla case for the same and have shared logs there? When I looked into the logs I can see 'node_mount_info' entry present in etcd information that you have shared.

This entry will exist if volume is mounted on some node. As long as etcd has this entry for a volume it is considered that volume is in mounted state. When volume is in mounted state plugin does not remove it.

'node_mount_info': {'3f33921d-cec5-45f6-924a-9a7db63ae53e': ['b68555e89efc804f8b1cce964744468dcd7e4bf5d7dec8968d6cc21da22eb7db']

Hence to analyze this issue, it is necessary for us to understand what were the exact steps to reproduce this issue?

Can you please provide following details:

OS of host machines
docker version
cat /etc/hpedockerplugin/hpe.conf
docker-compose.yml file
exact steps to reproduce issue:
- volume create command
- volume mount command ()
- how you performed fail-over
- when did removal of the volume was tried
- etc. Please provide the necessary information asked on bugzilla ticket, we can track the issue on bugzilla.

aironfonteles commented 5 years ago

@nilangekarss I've not directly opened a bugzilla case. What I did was to use HPE tools to open a case against L3 as instructed by engineer team.

Most of information you asked is already available here, on this very same 619 issue. Nevertheless, here follows my last update on the L3 ticket:

OS of host machines OS Revision: Red Hat Enterprise Linux Product Version: RHEL 7
docker version Docker Enterprise 18.09
cat /etc/hpedockerplugin/hpe.conf

Plugin File Configuration: SAME ON ALL 5 HOSTS

[DEFAULT] ssh_hosts_key_file = /root/.ssh/known_hosts

host_etcd_ip_address = 10.41.1.151 host_etcd_port_number = 2379

logging = ERROR hpe3par_debug = True

suppress_requests_ssl_warnings = True hpedockerplugin_driver = hpedockerplugin.hpe.hpe_3par_iscsi.HPE3PARISCSIDriver

hpe3par_api_url = https://10.88.50.20:8080/api/v1 hpe3par_username = MyCustomUser hpe3par_password = myCustomPass san_ip = *** san_login = **** san_password = **** hpe3par_cpg = **** hpe3par_snapcpg = **** hpe3par_iscsi_chap_enabled = False hpe3par_iscsi_ips = ****,****,****,****,****,****,**** use_multipath = True enforce_multipath = True replication_device = backend_id:3PAR-8400-RL1, quorum_witness_ip:****, replication_mode:synchronous, cpg_map:FC_r6_AO_Docker:****, snap_cpg_map:****:****, hpe3par_api_url:https://********:8080/api/v1, hpe3par_username:****, hpe3par_password:****, san_ip:****, san_login:****, san_password:****, hpe3par_iscsi_ips:****;****;****;****;****;****;****

docker-compose.yml file

Here is how I created the volume.

docker volume create -d hpe --name Docker-Vol-02 -o replicationGroup=BH-PP-RCG-Docker -o size=50 -o provisioning=thin

This yaml file is deployed as a “stack” in swarm via UCP UI. Here is the yaml file.

version: '3'

services: mysql: image: mysql:5.6 environment:

MYSQL_ROOT_PASSWORD=some pass volumes:
Docker-Vol-02:/var/lib/mysql

deploy: replicas: 1 restart_policy: condition: on-failure

networks:

ipamnet

ipam: depends_on:

mysql image: dtr.srv.fortlewis.edu/systems/phpipam:1.1 environment:
MYSQL_ENV_MYSQL_USER=root
MYSQL_ENV_MYSQL_ROOT_PASSWORD=some pass
MYSQL_ENV_MYSQL_HOST=mysql ports:
"20003:80"

networks:

ipamnet

deploy: replicas: 1 restart_policy: condition: on-failure

volumes:

Docker-Vol-02:

external: true

networks:

ipamnet:

As you can see I am saying that this docker volume mounts to the /var/lib/mysql directory on the container for the mysql service. All 5 of our nodes, 3 manager, and 2 worker all have the HPE plugin enabled. Is the volume config in the yaml file correct? External: true ?

Steps:

docker volume create -d hpe --name Docker-Vol-02 -o replicationGroup=BH-PP-RCG-Docker -o size=50 -o provisioning=thin
yaml file is deployed as a “stack” in swarm via UCP UI. Here is the yaml file.
Swarm restart to trigger failover
Docker volume rm Docker-Vol-02
Volume remove was tried on all nodes: I disabled all 3.1 plugins on all hosts except 1. Tried to remove the volume, did not work. I then stopped the docker engine on all hosts except the 1. Tried to remove the docker volume, it did not work. I disabled the plugin on the last host, enabled it, tried again. It did not remove the volume. I then started the docker engine on 2 hosts to get etcd cluster working properly. Tried to delete the volume, it did not work.

I finally uninstalled 3.1 plugin on one host. Disabled plugin and stopped the docker engine on all hosts except the one. Installed the 3.0 plugin as requested. I tried to remove the volume, and it did not work.

At every instance of the volume removal, the hpe plugin logs mention that the volume is locked.

2019-06-28 21:58:53,540 [ERROR] hpedockerplugin.etcdutil [139861408123784] MainThread Name: Docker-Vol-02 is already locked

complete logs of plugin container from all nodes where mount is tried you may get logs from /var/log/messages if plugin container version is 3.0 in case of 3.1 version of plugin you can capture from /etc/hpedockerplugin/3pardcv.log

“docker ps -a | grep -i hpe” yields no results. Because I am not running the plugin as a container. LOGS are available here: ftp://es661831:}DD2kv{Z@h1.ext.hpe.com

LAST ACTION PLAN TRIED BY CUSTOMER: $ docker volume inspect Docker-Vol-02 Take volume name in 3par_vol_name attribute, and in the connected 3PAR array showvlun -v vol_name removevlun -f for the LUN(s) involved in step 3 Now issue docker volume rm Docker-Vol-02

RESULTS: There are no results of the following commands on both of my 3par arrays

3PAR-8400-BH1 cli% showvlun -v dcv-EdcLHR5hQfOMrw2ciFwt2A

Active VLUNs no vluns listed

VLUN Templates no vluns listed

3PAR-8400-BH1 cli%

And

3PAR-8400-RL1 cli% showvlun -v dcv-EdcLHR5hQfOMrw2ciFwt2A.r

Active VLUNs no vluns listed

VLUN Templates no vluns listed

Any other ideas? Thanks.

aironfonteles commented 5 years ago

@nilangekarss Any updates on this? Thanks!

aironfonteles commented 5 years ago

@nilangekarss Please, I really need your assistance on this. Thanks!

hpe-storage / python-hpedockerplugin

Unable to use data on a volume in a different host #619