dm.thinpooldev lacks error handling #16092

docwhat · 2015-09-04T20:56:54Z

I created an LVM2 thin-pool. I then created a logical volume inside that pool, just to play with it.

I deleted my logical volume and then tried to use docker daemon with it and it would crash:

◀︎root@elastic01 ~▶︎ rm -rf /var/lib/docker ; /usr/bin/docker daemon --debug --storage-driver 'devicemapper' --storage-opt 'dm.thinpooldev=/dev/mapper/docker-pool0' --storage-opt 'dm.fs=xfs' --storage-opt 'dm.use_deferred_removal=true'
DEBU[0000] Registering PUT, /containers/{name:.*}/archive
DEBU[0000] Registering DELETE, /images/{name:.*}
DEBU[0000] Registering DELETE, /containers/{name:.*}
DEBU[0000] Registering OPTIONS,
DEBU[0000] Registering HEAD, /containers/{name:.*}/archive
DEBU[0000] Registering GET, /info
DEBU[0000] Registering GET, /images/{name:.*}/get
DEBU[0000] Registering GET, /images/{name:.*}/history
DEBU[0000] Registering GET, /containers/{name:.*}/changes
DEBU[0000] Registering GET, /containers/{name:.*}/json
DEBU[0000] Registering GET, /containers/{name:.*}/stats
DEBU[0000] Registering GET, /_ping
DEBU[0000] Registering GET, /images/search
DEBU[0000] Registering GET, /containers/{name:.*}/top
DEBU[0000] Registering GET, /exec/{id:.*}/json
DEBU[0000] Registering GET, /version
DEBU[0000] Registering GET, /images/json
DEBU[0000] Registering GET, /containers/ps
DEBU[0000] Registering GET, /containers/{name:.*}/export
DEBU[0000] Registering GET, /containers/{name:.*}/logs
DEBU[0000] Registering GET, /containers/{name:.*}/archive
DEBU[0000] Registering GET, /events
DEBU[0000] Registering GET, /images/{name:.*}/json
DEBU[0000] Registering GET, /containers/json
DEBU[0000] Registering GET, /containers/{name:.*}/attach/ws
DEBU[0000] Registering GET, /images/get
DEBU[0000] Registering POST, /containers/create
DEBU[0000] Registering POST, /containers/{name:.*}/stop
DEBU[0000] Registering POST, /containers/{name:.*}/wait
DEBU[0000] Registering POST, /containers/{name:.*}/rename
DEBU[0000] Registering POST, /images/create
DEBU[0000] Registering POST, /images/{name:.*}/push
DEBU[0000] Registering POST, /images/{name:.*}/tag
DEBU[0000] Registering POST, /containers/{name:.*}/attach
DEBU[0000] Registering POST, /auth
DEBU[0000] Registering POST, /containers/{name:.*}/kill
DEBU[0000] Registering POST, /containers/{name:.*}/pause
DEBU[0000] Registering POST, /containers/{name:.*}/unpause
DEBU[0000] Registering POST, /containers/{name:.*}/restart
DEBU[0000] Registering POST, /containers/{name:.*}/start
DEBU[0000] Registering POST, /exec/{name:.*}/start
DEBU[0000] Registering POST, /images/load
DEBU[0000] Registering POST, /build
DEBU[0000] Registering POST, /containers/{name:.*}/resize
DEBU[0000] Registering POST, /containers/{name:.*}/copy
DEBU[0000] Registering POST, /containers/{name:.*}/exec
DEBU[0000] Registering POST, /exec/{name:.*}/resize
DEBU[0000] Registering POST, /commit
DEBU[0000] [graphdriver] trying provided driver "devicemapper"
DEBU[0000] devicemapper: driver version is 4.29.0
DEBU[0000] devmapper: Deferred removal support enabled.
DEBU[0000] Generated prefix: docker-253:0-375713300
DEBU[0000] Checking for existence of the pool 'docker-pool0'
FATA[0000] Error starting daemon: error initializing graphdriver: EOF

After much digging around, I found the problem in the commit message for 2b10749:

Docker will not take ownership of the specified thin-pool device unless it has 0 data blocks used and a transaction id of 0. This should help guard against using a thin-pool that is already in use.

I rebuilt my LVM2 thin pool and now it works.

I would expect that instead of error initializing graphdriver: EOF it would display a message about the LVM2 thin pool have been used already or that it was invalid or something I could use to figure out the problem.

I also (stupidly, I admit) didn't understand the documentation and instead of doing a man lvmthin and working things out from there, I tried using /dev/sdb2 as the thinpool.

I would suggest a good error message for that would be handy. :-)

The text was updated successfully, but these errors were encountered:

thaJeztah · 2015-09-05T12:03:20Z

Thanks for reporting!

ping @rhvgoyal do you think we can do something better with the error message?

ghost · 2015-10-07T11:05:50Z

Information regarding my docker host

$ docker version
Client version: 1.7.1
Client API version: 1.19
Go version (client): go1.4.2
Git commit (client): df2f73d-dirty
OS/Arch (client): linux/amd64
Server version: 1.7.1
Server API version: 1.19
Go version (server): go1.4.2
Git commit (server): df2f73d-dirty
OS/Arch (server): linux/amd64

$ docker info
...
 Backing Filesystem: extfs
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.1.7-coreos
Operating System: CoreOS 766.4.0
CPUs: 1
Total Memory: 3.618 GiB

uname -a
Linux master-pgsql1 4.1.7-coreos #2 SMP Wed Sep 16 22:54:37 UTC 2015 x86_64 Intel(R) Xeon(R) CPU @ 2.30GHz GenuineIntel GNU/Linux

i have configured a lvm thinpool using this

parted -s ${DISK} mklabel gpt mkpart primary 1 100%
/usr/sbin/pvcreate ${DISK}1
/usr/bin/echo -e "y\n" | /usr/sbin/wipefs -f ${DISK}1
/usr/sbin/vgcreate docker ${DISK}1
/usr/sbin/lvcreate -l 99%VG --type thin-pool --thinpool thin_pool docker
METASIZE=$(/sbin/vgdisplay docker | awk '/Free  PE/ {print $(NF-1),$NF}' | sed 's/ //g')
lvresize --poolmetada ${METASIZE} docker/thin_pool

which i have confirmed that is ok

# lvs
  LV        VG     Attr       LSize   Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert
  thin_pool docker twi-a-tz-- 198.00g             0.00   0.03                            
# dmsetup status
docker-thin_pool-tpool: 0 415227904 thin-pool 0 136/472064 0/1621984 - rw discard_passdown queue_if_no_space 
docker-thin_pool_tdata: 0 415227904 linear 
docker-thin_pool_tmeta: 0 3776512 linear 
docker-thin_pool: 0 415227904 linear

but when i try to start docker as daemon to use this thinpool, i get this

/usr/bin/docker --daemon --debug --storage-driver 'devicemapper' --storage-opt 'dm.thinpooldev=/dev/mapper/docker-thin_pool'
DEBU[0000] Registering GET, /containers/{name:.*}/json  
DEBU[0000] Registering GET, /_ping                      
DEBU[0000] Registering GET, /images/{name:.*}/get       
DEBU[0000] Registering GET, /containers/json            
DEBU[0000] Registering GET, /containers/{name:.*}/changes 
DEBU[0000] Registering GET, /containers/{name:.*}/stats 
DEBU[0000] Registering GET, /events                     
DEBU[0000] Registering GET, /images/{name:.*}/json      
DEBU[0000] Registering GET, /containers/{name:.*}/export 
DEBU[0000] Registering GET, /images/search              
DEBU[0000] Registering GET, /images/{name:.*}/history   
DEBU[0000] Registering GET, /containers/ps              
DEBU[0000] Registering GET, /containers/{name:.*}/top   
DEBU[0000] Registering GET, /info                       
DEBU[0000] Registering GET, /version                    
DEBU[0000] Registering GET, /images/json                
DEBU[0000] Registering GET, /exec/{id:.*}/json          
DEBU[0000] Registering GET, /images/get                 
DEBU[0000] Registering GET, /containers/{name:.*}/logs  
DEBU[0000] Registering GET, /containers/{name:.*}/attach/ws 
DEBU[0000] Registering POST, /images/create             
DEBU[0000] Registering POST, /images/{name:.*}/push     
DEBU[0000] Registering POST, /containers/{name:.*}/kill 
DEBU[0000] Registering POST, /containers/{name:.*}/start 
DEBU[0000] Registering POST, /containers/{name:.*}/exec 
DEBU[0000] Registering POST, /exec/{name:.*}/start      
DEBU[0000] Registering POST, /containers/{name:.*}/rename 
DEBU[0000] Registering POST, /build                     
DEBU[0000] Registering POST, /images/{name:.*}/tag      
DEBU[0000] Registering POST, /containers/{name:.*}/pause 
DEBU[0000] Registering POST, /containers/{name:.*}/unpause 
DEBU[0000] Registering POST, /containers/{name:.*}/stop 
DEBU[0000] Registering POST, /containers/{name:.*}/copy 
DEBU[0000] Registering POST, /exec/{name:.*}/resize     
DEBU[0000] Registering POST, /containers/{name:.*}/restart 
DEBU[0000] Registering POST, /containers/{name:.*}/wait 
DEBU[0000] Registering POST, /auth                      
DEBU[0000] Registering POST, /commit                    
DEBU[0000] Registering POST, /images/load               
DEBU[0000] Registering POST, /containers/create         
DEBU[0000] Registering POST, /containers/{name:.*}/resize 
DEBU[0000] Registering POST, /containers/{name:.*}/attach 
DEBU[0000] Registering DELETE, /containers/{name:.*}    
DEBU[0000] Registering DELETE, /images/{name:.*}        
DEBU[0000] Registering OPTIONS,                         
DEBU[0000] [graphdriver] trying provided driver "devicemapper" 
DEBU[0000] devicemapper: driver version is 4.31.0       
DEBU[0000] Generated prefix: docker-8:9-168             
DEBU[0000] Checking for existence of the pool 'docker-thin_pool' 
FATA[0000] Error starting daemon: error initializing graphdriver: EOF

how can i know that is causing this?

rhvgoyal · 2015-10-07T18:03:42Z

We seem to have code to return right error if number of data blocks are not 0 or transaction id is not 0. I will debug it and see why it is not being returned.

unc (devices *DeviceSet) checkThinPool() error {
_, transactionID, dataUsed, _, _, _, err := devices.poolStatus()
if err != nil {
return err
}
if dataUsed != 0 {
return fmt.Errorf("Unable to take ownership of thin-pool (%s) that already has used data blocks",
devices.thinPoolDevice)
}
if transactionID != 0 {
return fmt.Errorf("Unable to take ownership of thin-pool (%s) with non-zero transaction ID",
devices.thinPoolDevice)
}
return nil
}

rhvgoyal · 2015-10-07T20:18:14Z

@docwhat @andre-freitas can you please try the patch attached to PR #16823 and see if it fixes the issue for you.

ghost · 2015-10-08T14:58:02Z

@rhvgoyal atm i can't test it atm because my host is a coreos (and they don't have any compiler tools). I will try to see if i can build docker from source it in another linux distro...

mglantz · 2016-01-13T09:46:08Z

Hitting this with Docker version 1.8.2, build a01dc02/1.8.2 on RHEL 7.2 (latest). Ended up having to delete the docker-pool LV. Eg:

systemctl stop docker
rm -rf /var/lib/docker
lvremove /dev/volumegroupxyz/docker-pool
docker-storage-setup
systemctl start docker

rhvgoyal · 2016-01-15T13:24:11Z

@mglantz This got fixed in 1.9. Try it.

geku · 2016-02-29T16:52:15Z

I work with version 1.10 and receive a meaningful error message error initializing graphdriver: devmapper: Unable to take ownership of thin-pool (docker-pool0) that already has used data blocks but unfortunately I don't understand how to create the thin-pool LV in the correct way and there is very little documentation about how to set it up for Docker when not on a RedHat/CentOS machine with the docker-storage-setup script.

thaJeztah · 2016-02-29T17:03:41Z

@geku there's information on configuring it in the "storage drivers" section of the documentation; https://docs.docker.com/engine/userguide/storagedriver/device-mapper-driver/#device-mapper-and-docker-performance

geku · 2016-02-29T17:17:31Z

@thaJeztah thanks a lot for the quick reply. I found this documentation already but according to the daemon flags documentation the usage of datadev and metadatadev is deprecated and replaced by thinpooldev. And thinpooldev is not documented afaik.

geku · 2016-02-29T17:21:48Z

So far I have found the following working solution:

pvcreate /dev/xvdb
vgcreate docker /dev/xvdb
lvcreate -y -l 90%VG --thin docker/pool0

But then, the metadata volume is too small I think:

  # lvs -a
  LV              VG     Attr       LSize   Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert
  [lvol0_pmspare] docker ewi-------  68.00m                                                    
  pool0           docker twi-a-tz-- 135.00g             0.64   1.46                            
  [pool0_tdata]   docker Twi-ao---- 135.00g                                                    
  [pool0_tmeta]   docker ewi-ao----  68.00m

geku · 2016-02-29T17:35:45Z

Finally I have a working solution where I can set the size of the data and metadata volume:

pvcreate /dev/xvdb
vgcreate docker /dev/xvdb
lvcreate -y -l 5%VG -n pool0meta docker
lvcreate -y -l 90%VG -n pool0 docker
lvconvert -y --thinpool docker/pool0 --poolmetadata docker/pool0meta

The Docker config is --storage-driver=devicemapper --storage-opt dm.thinpooldev=/dev/mapper/docker-pool0

rhvgoyal · 2016-02-29T17:58:03Z

@geku, if you are not using docker-storage-setup, then refer to man lvmthin to figure out how to setup thin pool.

seant-me · 2016-06-19T09:46:26Z

FYI, in my systemctl status docker, I was getting error:

time="2016-06-19T05:18:17.906673293-04:00" level=fatal msg="Error starting daemon: error initializing graphdriver: Unable to take ownership of thin-pool (docker_vg-docker--pool) that already has used data blocks"

running docker-storage-setup again did not fix error. I just kept getting output:
Logical volume "docker-pool" changed.

I had to manually remove logical volume with
lvremove /dev/mapper/docker_vg-docker--pool

then rerun docker-storage-setup, then restart docker and I am good to go.

thaJeztah added area/storage/devicemapper kind/enhancement Enhancements are not bugs or new features but can improve usability or performance. labels Sep 5, 2015

rhvgoyal mentioned this issue Oct 7, 2015

devmapper: Make sure device is a thin pool device #16823

Merged

vbatts closed this as completed in #16823 Oct 8, 2015

gbraad mentioned this issue Feb 28, 2017

Enable LVM usage on CentOS/RHEL images minishift/minishift#394

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

dm.thinpooldev lacks error handling #16092

dm.thinpooldev lacks error handling #16092

docwhat commented Sep 4, 2015

thaJeztah commented Sep 5, 2015

ghost commented Oct 7, 2015

rhvgoyal commented Oct 7, 2015

rhvgoyal commented Oct 7, 2015

ghost commented Oct 8, 2015

mglantz commented Jan 13, 2016

rhvgoyal commented Jan 15, 2016

geku commented Feb 29, 2016

thaJeztah commented Feb 29, 2016

geku commented Feb 29, 2016

geku commented Feb 29, 2016

geku commented Feb 29, 2016

rhvgoyal commented Feb 29, 2016

seant-me commented Jun 19, 2016

dm.thinpooldev lacks error handling #16092

dm.thinpooldev lacks error handling #16092

Comments

docwhat commented Sep 4, 2015

thaJeztah commented Sep 5, 2015

ghost commented Oct 7, 2015

rhvgoyal commented Oct 7, 2015

rhvgoyal commented Oct 7, 2015

ghost commented Oct 8, 2015

mglantz commented Jan 13, 2016

rhvgoyal commented Jan 15, 2016

geku commented Feb 29, 2016

thaJeztah commented Feb 29, 2016

geku commented Feb 29, 2016

geku commented Feb 29, 2016

geku commented Feb 29, 2016

rhvgoyal commented Feb 29, 2016

seant-me commented Jun 19, 2016