Bug 1290283 - Docker Storage Setup enters failed state, is confused looking for non-existent VG "sda2"
Docker Storage Setup enters failed state, is confused looking for non-existen...
Status: CLOSED INSUFFICIENT_DATA
Product: Fedora
Classification: Fedora
Component: docker (Show other bugs)
23
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Vivek Goyal
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-12-09 22:50 EST by Chris Murphy
Modified: 2015-12-18 15:10 EST (History)
10 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-12-18 15:10:37 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
journal with debug (231.71 KB, application/x-gzip)
2015-12-09 22:51 EST, Chris Murphy
no flags Details
sysconfig docker-storage-setup (2.37 KB, text/plain)
2015-12-10 03:04 EST, Chris Murphy
no flags Details

  None (edit)
Description Chris Murphy 2015-12-09 22:50:26 EST
Description of problem:


Version-Release number of selected component (if applicable):
docker-1.7.0-22.gitdcff4e1.fc23.x86_64

How reproducible:
Always, appears each boot.

Conditions/setup:
I started with a Fedora-Cloud_Atomic-x86_64-23.iso installation, converted and migrated to Btrfs. If the method of that installation matters, ask, and I'll detail it.



Actual results:

[   39.879188] f23a.localdomain docker-storage-setup[689]: Volume group "sda2" not found
[   39.879738] f23a.localdomain docker-storage-setup[689]: Cannot process volume group sda2

[..snip...]

[   41.021567] f23a.localdomain docker-storage-setup[689]: Metadata volume docker-poolmeta already exists. Not creating a new one.
[   41.036625] f23a.localdomain docker-storage-setup[689]: Please provide a volume group name
[   41.037179] f23a.localdomain docker-storage-setup[689]: Run `lvcreate --help' for more information.
[   41.039765] f23a.localdomain systemd[1]: Received SIGCHLD from PID 689 (docker-storage-).
[   41.040438] f23a.localdomain systemd[1]: Child 689 (docker-storage-) died (code=exited, status=3/NOTIMPLEMENTED)
[   41.040997] f23a.localdomain systemd[1]: docker-storage-setup.service: Child 689 belongs to docker-storage-setup.service
[   41.041241] f23a.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=docker-storage-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
[   41.041749] f23a.localdomain systemd[1]: docker-storage-setup.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED
[   41.042265] f23a.localdomain systemd[1]: docker-storage-setup.service: Changed start -> failed
[   41.042744] f23a.localdomain systemd[1]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=24 reply_cookie=0 error=n/a
[   41.043280] f23a.localdomain systemd[1]: docker-storage-setup.service: Job docker-storage-setup.service/start finished, result=failed
[   41.043764] f23a.localdomain systemd[1]: Failed to start Docker Storage Setup.
[   41.044331] f23a.localdomain systemd[1]: Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobRemoved cookie=25 reply_cookie=0 error=n/a
[   41.044913] f23a.localdomain systemd[1]: docker-storage-setup.service: Unit entered failed state.
[   41.045521] f23a.localdomain systemd[1]: docker-storage-setup.service: Failed with result 'exit-code'.
[   41.046065] f23a.localdomain systemd[1]: docker-storage-setup.service: cgroup is empty



Expected results:

Not this. Maybe that it finds existing Btrfs volumes? There are two of them, but neither are labeled sda2, so I'm not sure why docker-storage-setup thinks this is a VG since docker is rather Btrfs aware.


Additional info:


"Metadata volume docker-poolmeta already exists"  is also a bogus message. There's no LVM thinp setup on this system, there's no LVM PV even.
Comment 1 Chris Murphy 2015-12-09 22:51 EST
Created attachment 1104206 [details]
journal with debug

systemd.log_level=debug is set as boot param
journal -b -o short-monotonic
gzipped
Comment 2 Chris Murphy 2015-12-09 22:59:29 EST
-bash-4.3# bash -x docker-storage-setup 
+ set -e
+ POOL_LV_NAME=docker-pool
+ DATA_LV_NAME=docker-pool
+ META_LV_NAME=docker-poolmeta
+ DOCKER_STORAGE=/etc/sysconfig/docker-storage
+ '[' -e /usr/lib/docker-storage-setup/docker-storage-setup ']'
+ source /usr/lib/docker-storage-setup/docker-storage-setup
++ DATA_SIZE=60%FREE
++ CHUNK_SIZE=512K
++ GROWPART=false
++ AUTO_EXTEND_POOL=yes
++ POOL_AUTOEXTEND_THRESHOLD=60
++ POOL_AUTOEXTEND_PERCENT=20
+ '[' -e /etc/sysconfig/docker-storage-setup ']'
+ is_old_data_meta_mode
+ '[' '!' -f /etc/sysconfig/docker-storage ']'
+ grep -e '^DOCKER_STORAGE_OPTIONS=.*dm\.datadev' -e '^DOCKER_STORAGE_OPTIONS=.*dm\.metadatadev' /etc/sysconfig/docker-storage
+ return 1
++ awk '$2 ~ /^\/$/ && $1 !~ /rootfs/ { print $1 }' /proc/mounts
+ ROOT_DEV=/dev/sda2
++ lvs --noheadings -o vg_name /dev/sda2
++ sed -e 's/^ *//' -e 's/ *$//'
  Volume group "sda2" not found
  Cannot process volume group sda2
+ ROOT_VG=
++ pvs --noheadings -o pv_name,vg_name
++ awk '$2 ~ /^$/ { print $1 }'
+ ROOT_PVS=
+ VG_EXISTS=
+ '[' -z '' ']'
+ VG=
+ VG_EXISTS=1
+ '[' -z '' ']'
+ '[' -z 1 ']'
+ '[' -n '' ']'
+ grow_root_pvs
+ '[' -x /usr/bin/growpart ']'
+ '[' false '!=' true ']'
+ return
+ '[' -n '' ']'
+ setup_lvm_thin_pool
+ lvm_pool_exists
+ local lv_data
+ local lvname lv lvsize
++ lvs --noheadings -o lv_name,lv_attr --separator ,
++ sed -e 's/^ *//'
+ lv_data=
+ SAVEDIFS=' 	
'
+ IFS=' 	
'
+ return 1
+ create_lvm_thin_pool
+ create_metadata_lv
+ lvs -a /docker-poolmeta --noheadings
+ echo 'Metadata volume docker-poolmeta already exists. Not creating a new one.'
Metadata volume docker-poolmeta already exists. Not creating a new one.
+ return 0
+ create_data_lv
+ '[' '!' -n 60%FREE ']'
+ [[ 60%FREE == *%* ]]
+ lvcreate -l 60%FREE -n docker-pool
  Please provide a volume group name
  Run `lvcreate --help' for more information.
Comment 3 Chris Murphy 2015-12-09 23:51:55 EST
The way I read this
https://github.com/projectatomic/docker-storage-setup/blob/master/docker-storage-setup.1

I should create /etc/sysconfig/docker-storage-setup with a line

STORAGE_DRIVER=""

or 

STORAGE_DRIVER=

But this does nothing. I still get the same "sda" error when starting the service.

-bash-4.3# systemctl status docker-storage-setup
● docker-storage-setup.service - Docker Storage Setup
   Loaded: loaded (/usr/lib/systemd/system/docker-storage-setup.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Wed 2015-12-09 21:51:05 MST; 7s ago
  Process: 994 ExecStart=/usr/bin/docker-storage-setup (code=exited, status=3)
 Main PID: 994 (code=exited, status=3)

Dec 09 21:51:05 f23a.localdomain systemd[1]: Starting Docker Storage Setup...
Dec 09 21:51:05 f23a.localdomain docker-storage-setup[994]: Volume group "sda2" not found
Dec 09 21:51:05 f23a.localdomain docker-storage-setup[994]: Cannot process volume group sda2
Dec 09 21:51:05 f23a.localdomain docker-storage-setup[994]: Metadata volume docker-poolmeta already exists. Not creating a new one.
Dec 09 21:51:05 f23a.localdomain docker-storage-setup[994]: Please provide a volume group name
Dec 09 21:51:05 f23a.localdomain docker-storage-setup[994]: Run `lvcreate --help' for more information.
Dec 09 21:51:05 f23a.localdomain systemd[1]: docker-storage-setup.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED
Dec 09 21:51:05 f23a.localdomain systemd[1]: Failed to start Docker Storage Setup.
Dec 09 21:51:05 f23a.localdomain systemd[1]: docker-storage-setup.service: Unit entered failed state.
Dec 09 21:51:05 f23a.localdomain systemd[1]: docker-storage-setup.service: Failed with result 'exit-code'.
Comment 4 Chris Murphy 2015-12-10 00:18:58 EST
I now have the following, and I still get the same error about volume group sda2 not being found as if that's a hard coded name for some reason.

-bash-4.3# pvs
  PV         VG   Fmt  Attr PSize   PFree  
  /dev/sda4  VG   lvm2 a--  426.51g 126.36g
-bash-4.3# vgs
  VG   #PV #LV #SN Attr   VSize   VFree  
  VG     1   1   0 wz--n- 426.51g 126.36g
-bash-4.3# lvs
  LV          VG   Attr       LSize   Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert
  docker-pool VG   twi-a-tz-- 300.00g             0.00   0.44     


Next I create /etc/sysconfig/docker-storage-setup to include
DEV=VG
VG=VG

And I get:
Dec 09 22:15:59 f23a.localdomain systemd[1]: Starting Docker Storage Setup...
Dec 09 22:15:59 f23a.localdomain docker-storage-setup[1260]: Volume group "sda2" not found
Dec 09 22:15:59 f23a.localdomain docker-storage-setup[1260]: Cannot process volume group sda2
Dec 09 22:15:59 f23a.localdomain docker-storage-setup[1260]: 0
Dec 09 22:15:59 f23a.localdomain docker-storage-setup[1260]: /usr/bin/docker-storage-setup: line 235: * 2 - 2048 : syntax error: operand expected (error t... 2048 ")
Dec 09 22:15:59 f23a.localdomain docker-storage-setup[1260]: Logical volume "docker-pool" changed.
Dec 09 22:15:59 f23a.localdomain systemd[1]: Started Docker Storage Setup.
Hint: Some lines were ellipsized, use -l to show in full.


So it still looks for non-existent VG sda2. And new bug, it has a problem with line 235 which I'll file as a separate bug.
Comment 5 Chris Murphy 2015-12-10 03:04 EST
Created attachment 1104249 [details]
sysconfig docker-storage-setup

With this configuration file, setting only VG=VG, there's no longer an error message. But it also doesn't seem to do anything, docker.service still wants to use the btrfs driver, even though this config file says to use devicemapper, and specifies the volume group named VG to use as backing.

-bash-4.3# systemctl status docker-storage-setup
● docker-storage-setup.service - Docker Storage Setup
   Loaded: loaded (/usr/lib/systemd/system/docker-storage-setup.service; enabled; vendor preset: disabled)
   Active: inactive (dead) since Thu 2015-12-10 00:47:16 MST; 13min ago
  Process: 6743 ExecStart=/usr/bin/docker-storage-setup (code=exited, status=0/SUCCESS)
 Main PID: 6743 (code=exited, status=0/SUCCESS)

Dec 10 00:47:15 f23a.localdomain systemd[1]: Starting Docker Storage Setup...
Dec 10 00:47:15 f23a.localdomain docker-storage-setup[6743]: INFO: Volume group backing root filesystem could not be determined
Dec 10 00:47:16 f23a.localdomain docker-storage-setup[6743]: Logical volume "docker-pool" changed.
Dec 10 00:47:16 f23a.localdomain systemd[1]: Started Docker Storage Setup.


# systemctl status docker.service
Dec 10 00:48:02 f23a.localdomain docker[6272]: time="2015-12-10T00:48:02.123860683-07:00" level=info msg="[graphdriver] using prior storage driver \"btrfs\""
Comment 6 Vivek Goyal 2015-12-10 08:53:07 EST
Chris, 

volume group sda2 not found is an INFO message. In recent docker-storage-setup we have specifically prefixed it with "INFO" to make sure users don't get confused.

I think your rootfs should be on sda2 and that's why this message is coming. Right now d-s-s is trying to figure out if there is a volume group which is backing rootfs and if there is free space in that volume group which can be used to setup thin pool. So this message is part of that.

Real error is that there does not seem to be a volume group and one has not been specified by user using VG= option. So docker-storage-setup can not create a thin pool hence exits with error.
Comment 7 Chris Murphy 2015-12-10 13:20:29 EST
See comment 4. There is a volume group, named "VG", and it is specified in /etc/sysconfig/docker-storage-setup with VG=VG.

That VG is 2/3rd thin pool, and 1/3 empty, with no logical volumes. Yet docker-storage-setup doesn't create any logical volumes. And docker.service still says it's using the Btrfs driver, even though the docker-storage-setup configuration file has STORAGE_DRIVER=devicemapper.

I've also tried wiping /dev/sda4 (the PV for the VG), and setting DEVS=/dev/sda4 and seeing if docker-storage-setup will just create the PV-VG-LV on its own, but that causes this message:

Dec 10 11:10:13 f23a.localdomain docker-storage-setup[1135]: INFO: Volume group backing root filesystem could not be determined
Dec 10 11:10:13 f23a.localdomain docker-storage-setup[1135]: Partition specification unsupported at this time.
Dec 10 11:10:13 f23a.localdomain systemd[1]: docker-storage-setup.service: Main process exited, code=exited, status=1/FAILURE
Dec 10 11:10:13 f23a.localdomain systemd[1]: Failed to start Docker Storage Setup.
Comment 8 Vivek Goyal 2015-12-10 13:48:35 EST
Real error here is "Partition specification unsupported at this time". Whats in DEVS= filed of /etc/sysconfig/docker-storage-setup. Looks like it is a partition device instead of whole block device.
Comment 9 Dusty Mabe 2015-12-10 14:12:36 EST
(In reply to Vivek Goyal from comment #8)
> Real error here is "Partition specification unsupported at this time". Whats
> in DEVS= filed of /etc/sysconfig/docker-storage-setup. Looks like it is a
> partition device instead of whole block device.

Right. Is passing a partition not supported? It's still essentially a block device that can be made into a PV.
Comment 10 Chris Murphy 2015-12-10 14:47:37 EST
Even if DEVs= is commented out, and VG= is set to the name of the already created VG, docker-storage-setup doesn't appear to do anything. It doesn't create a thin pool in that VG. It doesn't create a thin logical volume in an already created thin pool.

So far as I can tell, docker-storage-setup expects one of two things: root fs is on LVM; or it's given an unpartitioned 2nd (or more) physical block device defined by DEVS=. It's not willing to use LVM on /dev/sda4 when root fs is Btrfs on /dev/sda2.
Comment 11 Vivek Goyal 2015-12-10 16:08:08 EST
(In reply to Dusty Mabe from comment #9)
> (In reply to Vivek Goyal from comment #8)
> > Real error here is "Partition specification unsupported at this time". Whats
> > in DEVS= filed of /etc/sysconfig/docker-storage-setup. Looks like it is a
> > partition device instead of whole block device.
> 
> Right. Is passing a partition not supported? It's still essentially a block
> device that can be made into a PV.

Dusty, right, at this point of time, passing in partition devices in DEVS= is not supported. I think reason being that we always partition a block device and then add it as PV.
Comment 12 Vivek Goyal 2015-12-10 16:09:57 EST
(In reply to Chris Murphy from comment #10)
> Even if DEVs= is commented out, and VG= is set to the name of the already
> created VG, docker-storage-setup doesn't appear to do anything. It doesn't
> create a thin pool in that VG. It doesn't create a thin logical volume in an
> already created thin pool.
> 
> So far as I can tell, docker-storage-setup expects one of two things: root
> fs is on LVM; or it's given an unpartitioned 2nd (or more) physical block
> device defined by DEVS=. It's not willing to use LVM on /dev/sda4 when root
> fs is Btrfs on /dev/sda2.

Chris,

If you comment out DEVS= and pass in an already existing volume group using VG=, then docker-storage-setup will try to create a thin pool from that volume group (as long as there is free space in that volume group).

Please send me the error you are facing and I can look at it.
Comment 13 Chris Murphy 2015-12-10 19:34:37 EST
OK, I'll start from scratch, seeing as there's plenty of user error here. If I get a clear reproducer, I'll file a new bug since it'd be sufficiently different from this one.
Comment 14 Daniel Walsh 2015-12-18 15:10:37 EST
I will close this bug then, reopen if I should not have.

Note You need to log in before you can comment on or make changes to this bug.