Syllable Forum Index Syllable
Syllable Forums
 
 FAQFAQ   SearchSearch   MemberlistMemberlist   UsergroupsUsergroups   RegisterRegister 
 ProfileProfile   Log in to check your private messagesLog in to check your private messages   Log inLog in 

0.6.7: qemu-img convert vmdk AFS bug

 
Post new topic   Reply to topic    Syllable Forum Index -> Bugs - Fixed
View previous topic :: View next topic  
Author Message
Vanders
The Knights of Syllable


Joined: 14 Sep 2007
Posts: 849

PostPosted: Wed Jun 03, 2009 7:55 am    Post subject: 0.6.7: qemu-img convert vmdk AFS bug Reply with quote

Converting a 512MB raw disc image to vmdk (VMWare) format with qemu-img triggers an AFS bug:

0:qemu-img:qemu-img : Failed to expand file with 3222487040 bytes. Shrunk to 2241534976
0:qemu-img:qemu-img : Wait for 2342 log blocks to be free(0)
(Above repeats)

With a modified AFS:

0:qemu-img:qemu-img : Failed to expand file with 3222487040 bytes. Shrunk to 2241534976
0:qemu-img:qemu-img : kernel panic : 2342 log blocks requested but only 2048 available for this volume!
(Stack trace)

AFS does not gracefully handle the case where the transaction is larger than the log. There is no indication why AFS fails to expand the file, or why the transaction is so large.
Back to top
View user's profile Send private message Send e-mail
Morph
The Knights of Syllable


Joined: 18 Oct 2007
Posts: 316
Location: Australia

PostPosted: Wed Jun 03, 2009 8:59 am    Post subject: Reply with quote

Did you do an strace to catch the offending syscall?
Back to top
View user's profile Send private message Visit poster's website
Vanders
The Knights of Syllable


Joined: 14 Sep 2007
Posts: 849

PostPosted: Wed Jun 03, 2009 9:13 am    Post subject: Reply with quote

You mean if it's calling write() for a very large block? Yes I guess that's possible, I'll get a trace.

I've added some extra debug output to afs_expand_file(), so now have:

0:qemu-img:qemu-img : Failed to expand file with 3222487040 bytes. Shrunk to 2241534976
0:qemu-img:qemu-img : 5335895 new, 0 old, pos 3146960, len 3222421504 (2241534976)

the figures are: nNewBlockCount, nOldBlockCount, nPos, nLen, (nLen + nPos)

That last figure *should* be 3225568464, by my math. I can only assume (& hope) the odd result is a bug in printk() (The types are off_t and I'm using %Ld)
Back to top
View user's profile Send private message Send e-mail
Vanders
The Knights of Syllable


Joined: 14 Sep 2007
Posts: 849

PostPosted: Wed Jun 03, 2009 9:29 am    Post subject: Reply with quote

The trace doesn't show anything particularly odd: it mostly lseeks & then writes 512 bytes at a time. The last few lines:

512 = write(4, ..., 512)
0 = lseek(3, 917504, 0, 0, ... )
65536 = read(3, ..., 65536)
0 = lseek(4, 0, 0, 2, ... )
Failed to expand...

Note that a) I'm writing this by hand (can't rely on the log being written), and b) strace does not print the details until the syscall is returning, so if this was caused a call to write() which is causing AFS to crash/hang, it won't return so isn't on the trace.

Going back up the trace I see something similar to the above:

512 = write(4, ..., 512)
0 = lseek(3, 917504, 0, 0, ... )
65536 = read(3, ..., 65536)
0 = lseek(4, 0, 0, 2, ... )
0 = ftruncate(4, 1611243520, 0)
(Continues)

So I'm going to suggest it's a call to ftruncate() which is causing this.
Back to top
View user's profile Send private message Send e-mail
Vanders
The Knights of Syllable


Joined: 14 Sep 2007
Posts: 849

PostPosted: Wed Jun 03, 2009 9:38 am    Post subject: Reply with quote

Confirmed that it's ftruncate() by adding a bit of debugging. ftruncate() is called with a size of 3222487040 bytes (from the previous size of 1611243520)
Back to top
View user's profile Send private message Send e-mail
Vanders
The Knights of Syllable


Joined: 14 Sep 2007
Posts: 849

PostPosted: Wed Jun 03, 2009 3:30 pm    Post subject: Reply with quote

Tracked the problem down to afs_truncate(), which was passing the full file size to afs_expand_file() instead of the delta: this was causing the size of the file to effectively double on each call to ftruncate()

A huge thanks to Michael "Mask of Destiny" Pavone for spoting the cause and & Anthony for debugging help.
Back to top
View user's profile Send private message Send e-mail
Display posts from previous:   
Post new topic   Reply to topic    Syllable Forum Index -> Bugs - Fixed All times are GMT - 6 Hours
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum


Powered by phpBB © 2001, 2005 phpBB Group