[ovz] Error in ploop_fname_cmp during CT restore, f's with other CT's?

[Geek]

Earlier in the evening, I restored container 2208 per client request.  It happens to be a Ploop device. One of the few f***ing ones left in production.


2015-03-26T21:29:36-0700 : Opening delta /vz/private/2208/root.hdd/root.hdd
2015-03-26T21:29:36-0700 : Adding delta dev=/dev/ploop42417 img=/vz/private/2208/root.hdd/root.hdd (rw)
2015-03-26T21:29:36-0700 : Mounting /dev/ploop42417p1 at /vz/root/2208 fstype=ext4 data='balloon_ino=12,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0,'
2015-03-26T21:29:36-0700 vzctl : CT 2208 : Container is mounted
2015-03-26T21:29:36-0700 vzctl : CT 2208 : Adding IP address(es): XXX.XXX.XXX.XXX
2015-03-26T21:29:39-0700 vzctl : CT 2208 : Setting CPU limit: 100
2015-03-26T21:29:39-0700 vzctl : CT 2208 : Setting CPU units: 1000
2015-03-26T21:29:39-0700 vzctl : CT 2208 : Setting CPUs: 1

All fine and dandy, then this at the last minute.:


2015-03-26T21:29:39-0700 : Error in ploop_fname_cmp (ploop.c:1068): stat  (deleted)/vz/root/1939/home/virtfs/topnetwo/home/topnetwo: No such file or directory

2015-03-26T21:29:39-0700 vzctl : CT 2208 : Container start in progress...
CT 1939?  What the crap?  
Usual EXT4 whining....




Mar 26 21:29:21 vzn-divinity kernel: [6601405.552534] EXT4-fs (ploop42417p1): INFO: recovery required on readonly filesystem
Mar 26 21:29:21 vzn-divinity kernel: [6601405.552537] EXT4-fs (ploop42417p1): write access will be enabled during recovery
Mar 26 21:29:22 vzn-divinity kernel: [6601406.571458] EXT4-fs (ploop42417p1): orphan cleanup on readonly fs
Mar 26 21:29:22 vzn-divinity kernel: [6601406.617009] EXT4-fs (ploop42417p1): 5 orphan inodes deleted
Mar 26 21:29:22 vzn-divinity kernel: [6601406.618661] EXT4-fs (ploop42417p1): recovery complete
Mar 26 21:29:22 vzn-divinity kernel: [6601406.618993] EXT4-fs (ploop42417p1): mounted filesystem with ordered data mode. Opts:
Mar 26 21:29:22 vzn-divinity kernel: [6601406.622097] EXT4-fs (ploop42417p1): loaded balloon from 12 (20975624 blocks)
Mar 26 21:29:36 vzn-divinity kernel: [6601421.102028]  ploop42417: p1
Mar 26 21:29:36 vzn-divinity kernel: [6601421.144646]  ploop42417: p1
Mar 26 21:29:36 vzn-divinity kernel: [6601421.253238] EXT4-fs (ploop42417p1): mounted filesystem with ordered data mode. Opts:
Mar 26 21:29:36 vzn-divinity kernel: [6601421.255557] EXT4-fs (ploop42417p1): loaded balloon from 12 (20975624 blocks)
Mar 26 21:29:36 vzn-divinity kernel: [6601421.263002] CT: 2208: started
Mar 26 21:29:40 vzn-divinity kernel: [6601424.440744] Core dump to |/usr/libexec/abrt-hook-ccpp 11 0 56 0 0 1427430580 e pipe failed

Since I've admittedly fudged a manual CT config before, here's 2208.conf. Normal as far as I can tell, yes? 


# -----------------------------------------------------------------------------------------------------
# Copyright 2011 John Edel, Jetfire Networks L.L.C.
# Refinements 2011-2015 Jetfire Networks L.L.C.
# Because you know I'm all about the maps, bout the maps, no Ploop
# -----------------------------------------------------------------------------------------------------

# Resource knobs

KMEMSIZE="268435456"
NUMPROC="unlimited"
VMGUARPAGES="0:unlimited"
NUMTCPSOCK="unlimited"
TCPSNDBUF="unlimited"
TCPRCVBUF="unlimited"
NUMOTHERSOCK="unlimited"
LOCKEDPAGES="unlimited"
PRIVVMPAGES="unlimited"
SHMPAGES="unlimited"
OOMGUARPAGES="0:unlimited"
NUMFLOCK="unlimited"
NUMPTY="unlimited"
OTHERSOCKBUF="unlimited"
DGRAMRCVBUF="unlimited"
NUMFILE="unlimited"
SWAPPAGES="0:262144"
DISKSPACE="5242880:5242880"
DISKINODES="2621440:2621440"
QUOTATIME="0"
QUOTAUGIDLIMIT="20000"
PHYSPAGES="0:262144"
NUMSIGINFO="unlimited"
DCACHESIZE="134217728"
NUMIPTENT="unlimited"
CPUUNITS="2000"
CPULIMIT="200"
CPUS="2"
HOSTNAME="XXXXX.XXXXX.XXX"
IP_ADDRESS="XXX.XXX.XXX.XXX"

# So says the node

ONBOOT="yes"
VE_ROOT="/vz/root/$VEID"
VE_PRIVATE="/vz/private/$VEID"
ORIGIN_SAMPLE="vswap-jetfire"
OSTEMPLATE="ct2208-vzdump"

# Additional CT capabilities

CAPABILITY="NET_ADMINn"
DEVNODES="net/tun:rw"
FEATURES="pppn"
DISABLED="no"
I can think of no reason why restoring one container would report anything about an entirely different one unless I'm doing something wrong and can't see it... 

Looks to be whining about a cPanel bind mount.  The only thing I can think is that CT 1939 removed that particular cPanel account (or perhaps removed it through WHMCS or the like) yet the bind mount might still exist...?  Well, it's a theory at least.

Of course, I can't/won't drop into CT 1939 until I get a green light from the client.  Right now I can only speculate. Both containers are operating and are in use, and I've had no reports of problems from their respective users, so ....I'm a little broken.

Anyone wanna take a guess at this?



-John

 

[devonblzx]

I don't see anything in the config.  You sure it is related to the start and not a separate notice?  I assume this is from your global log.

P.S.  Did your system just crash?  Is that why you have the read only notice and cleanup with ext4?

 

[Francisco]

Can you get it to at least mount? If so, extract all the data, ditch the ploop, live happy.

If not, I replied to your old thread a couple weeks/months ago documenting a PLOOP fix where OpenVZ was corrupting/losing its own partition table.

Francisco

 

[Geek]

Plugging along almost three months on this box... 094.8 is the current booted kernel.  KSplice has me up to 105.14, and I'm booted into the same kernel in QA.

I don't see how it could be a separate notice when the time stamp is identical, even down to the second.  

Going through back logs, I found something that I missed last night.


2015-03-26T21:29:20-0700 : Opening delta /vz/private/2208/root.hdd/root.hdd
2015-03-26T21:29:20-0700 : Trimming tail
2015-03-26T21:29:20-0700 : Error in ploop_check (check.c:572): Dirty flag is set
2015-03-26T21:29:20-0700 : Adding delta dev=/dev/ploop42417 img=/vz/private/2208/root.hdd/root.hdd (rw)
2015-03-26T21:29:22-0700 : Mounting /dev/ploop42417p1 at /vz/root/2208 fstype=ext4 data='balloon_ino=12,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0,'
2015-03-26T21:29:22-0700 vzctl : CT 2208 : Performing postcreate actions


....and it still booted.


Same restoration, different node.



[root@vzdevqa conf]# vzctl start 8877665
Starting container...
Error in ploop_umount_image (ploop.c:1976): Image /vz/private/8877665/root.hdd/root.hdd is not mounted
Failed to umount image: Error in ploop_umount_image (ploop.c:1976): Image /vz/private/8877665/root.hdd/root.hdd is not mounted [40]
Container start failed (try to check kernel messages, e.g. "dmesg | tail")
Killing container ...
Container was stopped
Error in ploop_umount_image (ploop.c:1976): Image /vz/private/8877665/root.hdd/root.hdd is not mounted
Failed to umount image: Error in ploop_umount_image (ploop.c:1976): Image /vz/private/8877665/root.hdd/root.hdd is not mounted [40]


So, it sounds like @Francisco is on the right track. 

Actually, you just got me thinking... client said I could restart his container for verification, and lookie there....



2015-03-27T12:15:56-0700 : Error in ploop_fname_cmp (ploop.c:1068): stat  (deleted)/vz/root/1939/home/virtfs/topnetwo/home/topnetwo: No such file or directory
Unfortunately, I'm not having much luck in the mount department, either.

[root@vzdevqa conf]# ploop mount /dev/ploop34190p1
Error in check_deltas (check.c:633): /dev/ploop34190p1 : irrecoverable errors (rw)

Destroyed problematic CT, Created with fresh OS and SimFS instead, then ran vzctl convert, generated a backup, destroyed again, restored again.. Mounted /dev/ploop34190p1 this time and the damn thing fired right up without touching CT 1939.  




2015-03-27T12:37:39-0700 vzctl : CT 3094 : Creating image: /vz/private/3094.ploop/root.hdd/root.hdd size=20971520K
2015-03-27T12:37:39-0700 : Creating delta /vz/private/3094.ploop/root.hdd/root.hdd bs=2048 size=335544320 sectors v2
2015-03-27T12:37:39-0700 : Storing /vz/private/3094.ploop/root.hdd/DiskDescriptor.xml
2015-03-27T12:37:39-0700 : Opening delta /vz/private/3094.ploop/root.hdd/root.hdd
2015-03-27T12:37:39-0700 : Adding delta dev=/dev/ploop34190 img=/vz/private/3094.ploop/root.hdd/root.hdd (rw)
2015-03-27T12:37:40-0700 : Creating balloon file .balloon-c3a5ae3d-ce7f-43c4-a1ea-c61e2b4504e8
2015-03-27T12:37:40-0700 : Mounting /dev/ploop34190p1 at /vz/private/3094.ploop/root.hdd/root.hdd.mnt fstype=ext4 data=''
2015-03-27T12:37:40-0700 : Unmounting device /dev/ploop34190
2015-03-27T12:37:40-0700 : Opening delta /vz/private/3094.ploop/root.hdd/root.hdd
2015-03-27T12:37:40-0700 : Adding delta dev=/dev/ploop34190 img=/vz/private/3094.ploop/root.hdd/root.hdd (rw)
2015-03-27T12:37:40-0700 : Mounting /dev/ploop34190p1 at /vz/private/3094.ploop/root.hdd/root.hdd.mnt fstype=ext4 data='balloon_ino=12,'
2015-03-27T12:37:40-0700 : Changing balloon size old_size=0 new_size=150325952512
2015-03-27T12:37:40-0700 : Opening delta /vz/private/3094.ploop/root.hdd/root.hdd
2015-03-27T12:37:41-0700 : Successfully inflated balloon from 0 to 150325952512 bytes
2015-03-27T12:37:41-0700 : No unused cluster blocks found
2015-03-27T12:37:41-0700 : Unmounting file system at /vz/private/3094.ploop/root.hdd/root.hdd.mnt
2015-03-27T12:37:41-0700 : Unmounting device /dev/ploop34190
2015-03-27T12:37:41-0700 : Opening delta /vz/private/3094.ploop/root.hdd/root.hdd
2015-03-27T12:37:41-0700 : Adding delta dev=/dev/ploop34190 img=/vz/private/3094.ploop/root.hdd/root.hdd (rw)
2015-03-27T12:37:41-0700 : Mounting /dev/ploop34190p1 at /vz/root/3094 fstype=ext4 data='balloon_ino=12,'
2015-03-27T12:37:41-0700 vzctl : CT 3094 : Copying content to ploop...
2015-03-27T12:38:00-0700 : Unmounting file system at /vz/root/3094
2015-03-27T12:38:05-0700 : Unmounting device /dev/ploop34190
2015-03-27T12:38:06-0700 vzctl : CT 3094 : Container was successfully converted to the ploop layout
2015-03-27T12:39:22-0700 vzctl : CT 3094 : Starting container...
2015-03-27T12:39:23-0700 : Opening delta /vz/private/3094/root.hdd/root.hdd
2015-03-27T12:39:23-0700 : Adding delta dev=/dev/ploop34190 img=/vz/private/3094/root.hdd/root.hdd (rw)
2015-03-27T12:39:23-0700 : Mounting /dev/ploop34190p1 at /vz/root/3094 fstype=ext4 data='balloon_ino=12,'
2015-03-27T12:39:23-0700 vzctl : CT 3094 : Container is mounted


.  Worried now about when SimFS is officially EOL/unsupported.  Glad to have KVM nodes ready to go in April.  Wow, never thought I'd catch myself saying that...scattered now.  Time for a nap soon...

 

[Geek]

I had to be honest with that client -- that he happened to join just as Ploop was replaced as the default layout, and that I'd probably lie awake at night unless he let me credit him and start fresh.  He agreed, and it took less time to set up the configuration cluster and migrate his users over than it did for me to finally get the damn thing mounted. No room for risk though... not in my house.  One more saved from Ploop's schizophrenic ways, at least.

Dunno what I'm going to do about 1939.  Looks to be running fine and no reports have come in.  Do you think it's in poor taste to request access as a preventive measure?  At least to check the logs, etc..  Honesty hasn't failed me yet.