Skip to content
This repository has been archived by the owner on Nov 9, 2020. It is now read-only.

Handle datastores with spaces or special characters #1116

Closed
ashahi1 opened this issue Mar 30, 2017 · 9 comments
Closed

Handle datastores with spaces or special characters #1116

ashahi1 opened this issue Mar 30, 2017 · 9 comments
Assignees
@govint
Labels
Blocker customer kind/bug P0

Comments

@ashahi1
Copy link
Contributor

ashahi1 commented Mar 30, 2017 •
edited

ESX has 10 VMs and I am trying to create volumes from each VM simultaneously.

Volume creation failed from one of the VMs:

Error response from daemon: create dockerVol_syQvQ: VolumeDriver.Create: Server returned an error: IndexError('list index out of range',)

docker volume ls:

root@photon-xVmYMbyTn [ ~ ]# docker volume ls
DRIVER              VOLUME NAME
vsphere             dockerVol_syQvQ@sharedVmfs-0
root@photon-xVmYMbyTn [ ~ ]# docker volume inspect dockerVol_syQvQ@sharedVmfs-0
[
    {
        "Name": "dockerVol_syQvQ@sharedVmfs-0",
        "Driver": "vsphere",
        "Mountpoint": "/mnt/vmdk/dockerVol_syQvQ@sharedVmfs-0",
        "Status": {
            "access": "read-write",
            "attach-as": "independent_persistent",
            "attached to VM": "Photon-Dker-9",
            "capacity": {
                "allocated": "100MB",
                "size": "100MB"
            },
            "clone-from": "None",
            "created": "Thu Mar 30 07:43:04 2017",
            "created by VM": "Photon-Dker-9",
            "datastore": "sharedVmfs-0",
            "diskformat": "eagerzeroedthick",
            "fstype": "ext4",
            "status": "attached"     <<<<<<<<<<<<<<<<<<<
        },
        "Labels": {},
        "Scope": "global"
    }
]
root@photon-xVmYMbyTn [ ~ ]#

root@photon-xVmYMbyTn [ ~ ]# journalctl -u docker.service
-- Logs begin at Thu 2017-03-30 06:52:17 UTC, end at Thu 2017-03-30 07:52:56 UTC. --
Mar 30 06:52:22 photon-xVmYMbyTn systemd[1]: Starting Docker Daemon...
Mar 30 06:52:24 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:24.934076798Z" level=warning msg="[!] DON'T BIND ON ANY IP ADDRESS WITHOUT setting -tlsverify IF YOU DON'T KNOW WHAT YOU'RE DOING [!
]"
Mar 30 06:52:24 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:24.950144734Z" level=info msg="libcontainerd: new containerd process, pid: 267"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.145293389Z" level=info msg="[graphdriver] using prior storage driver \"overlay\""
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.193657188Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194647003Z" level=warning msg="Your kernel does not support kernel memory limit."
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194771383Z" level=warning msg="Your kernel does not support cgroup blkio weight"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194789849Z" level=warning msg="Your kernel does not support cgroup blkio weight_device"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194835581Z" level=warning msg="Your kernel does not support cgroup blkio throttle.read_bps_device"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194852957Z" level=warning msg="Your kernel does not support cgroup blkio throttle.write_bps_device"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194866560Z" level=warning msg="Your kernel does not support cgroup blkio throttle.read_iops_device"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.194890336Z" level=warning msg="Your kernel does not support cgroup blkio throttle.write_iops_device"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.195170094Z" level=warning msg="mountpoint for pids not found"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.197585176Z" level=info msg="Loading containers: start."
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.454934006Z" level=info msg="Firewalld running: false"
Mar 30 06:52:25 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:25.912349332Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be use
d to set a preferred IP address"
Mar 30 06:52:26 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:26.029022027Z" level=info msg="Loading containers: done."
Mar 30 06:52:26 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:26.032519611Z" level=info msg="Daemon has completed initialization"
Mar 30 06:52:26 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:26.032562027Z" level=info msg="Docker daemon" commit=78d1802 graphdriver=overlay version=1.12.6
Mar 30 06:52:26 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:26.128105976Z" level=info msg="API listen on /var/run/docker.sock"
Mar 30 06:52:26 photon-xVmYMbyTn systemd[1]: Started Docker Daemon.
Mar 30 06:52:26 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T06:52:26.129810468Z" level=info msg="API listen on [::]:2375"

Mar 30 07:43:07 photon-xVmYMbyTn dockerd[243]: time="2017-03-30T07:43:07.592665059Z" level=error msg="Handler for POST /v1.24/volumes/create returned error: create dockerVol_syQvQ: VolumeDriver.Create:
Server returned an error: IndexError('list index out of range',)"         

root@photon-xVmYMbyTn [ ~ ]#

Logs:
vmdk_ops.1.txt
vmdk_ops.txt
docker-volume-vsphere.txt
@ashahi1 ashahi1 added this to the v1 GA milestone Mar 30, 2017
@ashahi1 ashahi1 mentioned this issue Mar 30, 2017
Closed
@govint
Copy link
Contributor

govint commented Mar 30, 2017

@ashahi1 can you check that the host is having the datastores on it. The exception is not handled in vmdk_utils.py:get_datastore_name() and should be fixed, but the ESX service is complaining that local-0 and local-1 datastores aren't available,

03/30/17 07:43:07 463428 [MainThread] [WARNING] dockvols creation failed - No such file or directory on datastore local-0 (11)
03/30/17 07:43:07 463428 [MainThread] [WARNING] dockvols creation failed - No such file or directory on datastore local-1 (11)
03/30/17 07:43:08 227484 [Photon-Dker-11-nolock-list] [WARNING] dockvols creation failed - No such file or directory on datastore local-0 (11)
03/30/17 07:43:08 227484 [Photon-Dker-11-nolock-list] [WARNING] dockvols creation failed - No such file or directory on datastore local-1 (11)

Can you check the ESX host to see the datastores are present and accessible. Run esxcfg-scsidevs -m
on the host and post it here.

@govint
Copy link
Contributor

govint commented Mar 30, 2017

And for all these tests its a good thing to run the ESX service with log level set to DEBUG in /etc/vmware/vmdkops/log_config.json. The trail is easier to debug with values of variables logged.

@ashahi1
Copy link
Contributor Author

ashahi1 commented Mar 30, 2017

@govint I checked from the VC and all the host's datastores look fine. I just ran a test that created 800 Volumes on the same setup but didn't see any issue.

[root@sc-rdops-vm04-dhcp-100-4:~] esxcfg-scsidevs -m
eui.3361356461366137:1                                           /vmfs/devices/disks/eui.3361356461366137:1 58d1fd9f-208947b1-c80d-0200088228d5  0  sharedVmfs-0
eui.3533393266373935:1                                           /vmfs/devices/disks/eui.3533393266373935:1 58d1fda1-5c4b81b4-166f-0200088228d5  0  sharedVmfs-1
eui.3637373535663063:1                                           /vmfs/devices/disks/eui.3637373535663063:1 58d1fda2-855b56a7-2209-0200088228d5  0  sharedVmfs-2
eui.3430333036666532:1                                           /vmfs/devices/disks/eui.3430333036666532:1 58d1fda4-95ba1b6e-b83b-0200088228d5  0  sharedVmfs-3
mpx.vmhba2:C0:T0:L0:1                                            /vmfs/devices/disks/mpx.vmhba2:C0:T0:L0:1  58d1fe76-8d7cd4b2-9a77-020008132d8f  0  local-0 (11)
mpx.vmhba1:C0:T0:L0:3                                            /vmfs/devices/disks/mpx.vmhba1:C0:T0:L0:3  58d1fe81-9d189cd5-7be7-020008132d8f  0  local-1 (11)
[root@sc-rdops-vm04-dhcp-100-4:~]

@govint
Copy link
Contributor

govint commented Mar 30, 2017 •
edited

@ashahi1 can you also get the docker host system logs (journalctl --no-pager --system > ). The plugin seems to have restarted when removing volumes. Was that a manual restart?

2017-03-30 05:59:19.292149597 +0000 UTC [INFO] Removing volume name="dockerVol_fONzs"
2017-03-30 05:59:20.826717098 +0000 UTC [INFO] Removing volume name="dockerVol_J3qqs"
2017-03-30 05:59:23.66656064 +0000 UTC [INFO] Removing volume name="dockerVol_fM4pf"
2017-03-30 05:59:26.499481446 +0000 UTC [INFO] Removing volume name="dockerVol_kiSG1"
2017-03-30 06:52:19.115123751 +0000 UTC [INFO] No config file found. Using defaults.
2017-03-30 06:52:19.140669111 +0000 UTC [WARNING] Failed to load config file /etc/docker-volume-vsphere.conf: open /etc/docker-volume-vsphere.conf: no such file or directory
2017-03-30 06:52:19.140746634 +0000 UTC [INFO] Starting plugin config="/etc/docker-volume-vsphere.conf" driver=vsphere log_level=info
2017-03-30 06:52:19.140881675 +0000 UTC [INFO] Plugin options - port=1019
2017-03-30 06:52:19.141053076 +0000 UTC [INFO] Docker VMDK plugin started version="vSphere Volume Driver v0.4" port=1019 mock_esx=false

May not be related to this issue,. just want to know if there was a crash and restart of the plugin.

@ashahi1
Copy link
Contributor Author

ashahi1 commented Mar 30, 2017

@govint No, I did not do any manual restart of the plugin.

Host system logs:
hostSystemLogs.txt

@govint govint self-assigned this Mar 31, 2017
@govint
Copy link
Contributor

govint commented Mar 31, 2017

No plugin panic in the logs one explanation for this behavior is like this:

  1. ESX service is started and it discovers all datastores on the host.
  2. Requests are received and handled.
  3. A request is received which is specifying a datastore thats not in the in mem cache used by the service and its not the default either.
  4. vmdk_utils.py: get_datastore_name() walks thru the cache and doesn't find the entry but accesses the empty list ......

@govint
Copy link
Contributor

govint commented Mar 31, 2017 •
edited

From the exception stack, it looks like the VM datastore is "for some reason" not in the datastores list - in mem. cache - used by the service. It may be local-0 or local-1 because along with the exception stack we also see the messages related to dockvols path missing on local-0 and local-1.

03/30/17 07:43:04 463408 [MainThread] [WARNING] dockvols creation failed - No such file or directory on datastore local-0 (11)

03/30/17 07:43:06 227484 [Photon-Dker-8-nolock-list] [WARNING] dockvols creation failed - No such file or directory on datastore local-1 (11)

Why the datastore isn't in the datastores list is because if the dockvols can't be created (which is called from init_data_stores in vmdk_utils.py) then we ignore the datastore. Any request from a VM on that datastore is always going to fail and with an exception.

The dockvols folder isn't getting created because the datastore is named as "local-0 (11)", which causes the mkdir command to fail, as reproduced locally below, with a datastore named "bigone (1)".

04/03/17 09:58:33 1169339 [Thread-4] [WARNING] dockvols creation failed - No such file or directory on datastore bigone (1)
04/03/17 09:58:34 1169339 [Thread-4] [WARNING] dockvols creation failed - No such file or directory on datastore bigone (1)

This was referenced Apr 3, 2017
Closed
Merged
@pdhamdhere
Copy link
Contributor

Customer is running into this issue. Bumping the priority.

@tusharnt tusharnt modified the milestones: 0.14, v1 GA Apr 7, 2017
@tusharnt tusharnt changed the title Volume creation failed Handle datastores with spaces or special characters Apr 10, 2017
@govint
Copy link
Contributor

govint commented Apr 14, 2017

Fixed via #1140

@govint govint closed this as completed Apr 14, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@govint govint

Labels
Blocker customer kind/bug P0
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@tusharnt @govint @pdhamdhere @ashahi1