running iozone on bcache0 device yields wrongly read data

running iozone on bcache0 device yields wrongly read data

[Carsten Aulbert]

[-- Attachment #1.1: Type: text/plain, Size: 1074 bytes --]

Hi all

I've spent some time on IRC today (thanks eegiks for input) but I fear
the problem I encountered is not solved yet.

http://pastebin.com/t0di2MKi

has some kind of summary on which kind of machine I am running and what
command lines switches I use for iozone. It seems I need to go at least
to -s 1g to start triggering this issue (latest run output attached).

I've tried it with an almost vanilla 3.11.0 and a patched
3.11.1+bcache-for-3.11 kernel but both show this issue. A cross test on
a similar host but only using an HDD did not show this issue.

Any clues/hints how to figure out if this is caused by the underlying
hardware or if this is something internal to bcache? What else would you
need as input? Shall I switch on debugging and what can I do to help you
figure out what's wrong?

Cheers

Carsten

-- 
Dr. Carsten Aulbert - Max Planck Institute for Gravitational Physics
Callinstrasse 38, 30167 Hannover, Germany
phone/fax: +49 511 762-17185 / -17193
https://wiki.atlas.aei.uni-hannover.de/foswiki/bin/view/ATLAS/WebHome

[-- Attachment #1.2: iozone-max-attack-bcache2 --]
[-- Type: text/plain, Size: 10096 bytes --]

	Iozone: Performance Test of File I/O
	        Version $Revision: 3.397 $
		Compiled for 64 bit mode.
		Build: linux-AMD64 

	Contributors:William Norcott, Don Capps, Isom Crawford, Kirby Collins
	             Al Slater, Scott Rhine, Mike Wisner, Ken Goss
	             Steve Landherr, Brad Smith, Mark Kelly, Dr. Alain CYR,
	             Randy Dunlap, Mark Montague, Dan Million, Gavin Brebner,
	             Jean-Marc Zucconi, Jeff Blomberg, Benny Halevy, Dave Boone,
	             Erik Habbinga, Kris Strecker, Walter Wong, Joshua Root,
	             Fabrice Bacchella, Zhenghua Xue, Qin Li, Darren Sawyer.
	             Ben England.

	Run began: Tue Sep 17 18:39:01 2013

	Excel chart generation enabled
	Include fsync in write timing
	File size set to 2097152 KB

	Machine = Linux cass1 3.11.1-atlas #3 SMP Tue Sep 17 18:26:12 CEST 2013 x86_64	Record Size 128 KB
	Record Size 128 KB
	Command line used: iozone -R -e -s 2g -t 32 -M -r 128k
	Output is in Kbytes/sec
	Time Resolution = 0.000001 seconds.
	Processor cache size set to 1024 Kbytes.
	Processor cache line size set to 32 bytes.
	File stride size set to 17 * record size.
	Throughput test with 32 processes
	Each process writes a 2097152 Kbyte file in 128 Kbyte records

	Children see throughput for 32 initial writers 	=   81557.54 KB/sec
	Parent sees throughput for 32 initial writers 	=   79863.75 KB/sec
	Min throughput per process 			=    2480.14 KB/sec 
	Max throughput per process 			=    2609.36 KB/sec
	Avg throughput per process 			=    2548.67 KB/sec
	Min xfer 					= 2011904.00 KB

	Children see throughput for 32 rewriters 	=   79110.97 KB/sec
	Parent sees throughput for 32 rewriters 	=   78721.56 KB/sec
	Min throughput per process 			=    2440.14 KB/sec 
	Max throughput per process 			=    2573.24 KB/sec
	Avg throughput per process 			=    2472.22 KB/sec
	Min xfer 					= 2015616.00 KB

	Children see throughput for 32 readers 		=   63335.91 KB/sec
	Parent sees throughput for 32 readers 		=   63320.14 KB/sec
	Min throughput per process 			=    1901.33 KB/sec 
	Max throughput per process 			=    2106.96 KB/sec
	Avg throughput per process 			=    1979.25 KB/sec
	Min xfer 					= 1892608.00 KB

	Children see throughput for 32 re-readers 	=   66402.77 KB/sec
	Parent sees throughput for 32 re-readers 	=   66381.13 KB/sec
	Min throughput per process 			=    1966.24 KB/sec 
	Max throughput per process 			=    2207.88 KB/sec
	Avg throughput per process 			=    2075.09 KB/sec
	Min xfer 					= 1867776.00 KB

	Children see throughput for 32 reverse readers 	=   28092.60 KB/sec
	Parent sees throughput for 32 reverse readers 	=   28089.99 KB/sec
	Min throughput per process 			=     810.85 KB/sec 
	Max throughput per process 			=     949.42 KB/sec
	Avg throughput per process 			=     877.89 KB/sec
	Min xfer 					= 1791360.00 KB


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff202000
Error in file: Position 1172054016 
Record # 8942 Record size 128 kb 
where 7ff9ff202000 loop 8192


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1156698112 
Record # 8824 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 1205641216 
Record # 9198 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1232588800 
Record # 9403 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 920768512 
Record # 7024 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 983289856 
Record # 7501 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 876335104 
Record # 6685 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20e000
Error in file: Position 990044160 
Record # 7553 Record size 128 kb 
where 7ff9ff20e000 loop 57344


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1110298624 
Record # 8470 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 898801664 
Record # 6857 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1036898304 
Record # 7910 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1052495872 
Record # 8029 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 996921344 
Record # 7605 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff202000
Error in file: Position 967843840 
Record # 7384 Record size 128 kb 
where 7ff9ff202000 loop 8192


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff202000
Error in file: Position 1025777664 
Record # 7826 Record size 128 kb 
where 7ff9ff202000 loop 8192


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 1110482944 
Record # 8472 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 925618176 
Record # 7061 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff202000
Error in file: Position 1143873536 
Record # 8727 Record size 128 kb 
where 7ff9ff202000 loop 8192


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20e000
Error in file: Position 803135488 
Record # 6127 Record size 128 kb 
where 7ff9ff20e000 loop 57344


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1166135296 
Record # 8896 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1035194368 
Record # 7897 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff202000
Error in file: Position 1121460224 
Record # 8556 Record size 128 kb 
where 7ff9ff202000 loop 8192


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 1036951552 
Record # 7911 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1088147456 
Record # 8301 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 1208602624 
Record # 9220 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 972333056 
Record # 7418 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 970182656 
Record # 7401 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 1054908416 
Record # 8048 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 890150912 
Record # 6791 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 983945216 
Record # 7506 Record size 128 kb 
where 7ff9ff21d000 loop 118784


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff20a000
Error in file: Position 825532416 
Record # 6298 Record size 128 kb 
where 7ff9ff20a000 loop 40960


Error in file: Found ?6d? Expecting ?6d6d6d6d6d6d6d6d? addr 7ff9ff21d000
Error in file: Position 710004736 
Record # 5416 Record size 128 kb 
where 7ff9ff21d000 loop 118784

	Children see throughput for 32 stride readers 	=       0.00 KB/sec
	Parent sees throughput for 32 stride readers 	=       0.00 KB/sec
	Min throughput per process 			=       0.00 KB/sec 
	Max throughput per process 			=       0.00 KB/sec
	Avg throughput per process 			=       0.00 KB/sec
	Min xfer 					=       0.00 KB
iozone.DUMMY.30: No such file or directory
iozone.DUMMY.28: No such file or directory
iozone.DUMMY.20: No such file or directory
iozone.DUMMY.19: No such file or directory
iozone.DUMMY.26: No such file or directory
iozone.DUMMY.0: No such file or directory
iozone.DUMMY.21: No such file or directory
iozone.DUMMY.18: No such file or directory
iozone.DUMMY.1: No such file or directory
iozone.DUMMY.22: No such file or directory
iozone.DUMMY.16: No such file or directory
iozone.DUMMY.2: No such file or directory
iozone.DUMMY.3: No such file or directory
iozone.DUMMY.23: No such file or directory
iozone.DUMMY.17: No such file or directory
iozone.DUMMY.4: No such file or directory
iozone.DUMMY.5: No such file or directory
iozone.DUMMY.24: No such file or directory
iozone.DUMMY.15: No such file or directory
iozone.DUMMY.6: No such file or directory
iozone.DUMMY.7: No such file or directory
iozone.DUMMY.25: No such file or directory
iozone.DUMMY.14: No such file or directory
iozone.DUMMY.8: No such file or directory
iozone.DUMMY.13: No such file or directory
iozone.DUMMY.9: No such file or directory
iozone.DUMMY.12: No such file or directory
iozone.DUMMY.11: No such file or directory
iozone.DUMMY.10: No such file or directory
iozone.DUMMY.29: No such file or directory
iozone.DUMMY.27: No such file or directory
iozone.DUMMY.31: No such file or directory

[-- Attachment #2: S/MIME Cryptographic Signature --]
[-- Type: application/pkcs7-signature, Size: 2044 bytes --]

Re: running iozone on bcache0 device yields wrongly read data

[Kent Overstreet]

On Tue, Sep 17, 2013 at 09:17:57PM +0200, Carsten Aulbert wrote:
> Hi all
> 
> I've spent some time on IRC today (thanks eegiks for input) but I fear
> the problem I encountered is not solved yet.
> 
> http://pastebin.com/t0di2MKi
> 
> has some kind of summary on which kind of machine I am running and what
> command lines switches I use for iozone. It seems I need to go at least
> to -s 1g to start triggering this issue (latest run output attached).
> 
> I've tried it with an almost vanilla 3.11.0 and a patched
> 3.11.1+bcache-for-3.11 kernel but both show this issue. A cross test on
> a similar host but only using an HDD did not show this issue.
> 
> Any clues/hints how to figure out if this is caused by the underlying
> hardware or if this is something internal to bcache? What else would you
> need as input? Shall I switch on debugging and what can I do to help you
> figure out what's wrong?

What's your setup? Are you running md, lvm? What filesystem?

I'm getting a couple bug reports, and I think I know what commit
introduced the regression but it seems to require something else
slightly unusual in the stack to trigger, so I'm trying to figure out
what the common factor is.

Re: running iozone on bcache0 device yields wrongly read data

[Carsten Aulbert]

[-- Attachment #1: Type: text/plain, Size: 1841 bytes --]

Hi

On 09/17/2013 10:40 PM, Kent Overstreet wrote:
> What's your setup? Are you running md, lvm? What filesystem?

Very basic, no md or LVM involved. /dev/sda2 is the backing device and
/dev/sdb is the cache device. On top of bcache0 I'm running xfs:

# parted -s /dev/sda p
Model: ATA Hitachi HDP72505 (scsi)
Disk /dev/sda: 500GB
Sector size (logical/physical): 512B/512B
Partition Table: msdos

Number  Start   End     Size    Type     File system     Flags
 1      1049kB  10.5GB  10.5GB  primary  xfs             boot
 2      10.5GB  499GB   489GB   primary
 3      499GB   500GB   1049MB  primary  linux-swap(v1)

# parted -s /dev/sdb p
Error: /dev/sdb: unrecognised disk label

# grep bcache /proc/mounts
/dev/bcache0 /srv xfs rw,relatime,attr2,inode64,noquota 0 0

# bcache-super-show /dev/sda2
sb.magic                ok
sb.first_sector         8 [match]
sb.csum                 7B66B1004B52FD9A [match]
sb.version              1 [backing device]

dev.uuid                3a131733-7d54-4feb-bf8c-62d6fbdbf935
dev.sectors_per_block   1
dev.sectors_per_bucket  1024
dev.data.first_sector   16
dev.data.cache_mode     1 [writeback]
dev.data.cache_state    1 [clean]

cset.uuid               2a108307-bab9-42dd-b072-10eeb0c13dd8


# bcache-super-show /dev/sdb
sb.magic                ok
sb.first_sector         8 [match]
sb.csum                 88965AD15D35A500 [match]
sb.version              3 [cache device]

dev.uuid                ffb6fc80-1dca-42d4-a951-cddee6af689e
dev.sectors_per_block   1
dev.sectors_per_bucket  1024
dev.cache.first_sector  1024
dev.cache.cache_sectors 62498816
dev.cache.total_sectors 62499840
dev.cache.discard       no
dev.cache.pos           0

cset.uuid               2a108307-bab9-42dd-b072-10eeb0c13dd8

Does this help?

cheers

Carsten


[-- Attachment #2: S/MIME Cryptographic Signature --]
[-- Type: application/pkcs7-signature, Size: 2044 bytes --]

Re: running iozone on bcache0 device yields wrongly read data

[Kent Overstreet]

On Wed, Sep 18, 2013 at 06:34:21AM +0200, Carsten Aulbert wrote:
> Hi
> 
> On 09/17/2013 10:40 PM, Kent Overstreet wrote:
> > What's your setup? Are you running md, lvm? What filesystem?
> 
> Very basic, no md or LVM involved. /dev/sda2 is the backing device and
> /dev/sdb is the cache device. On top of bcache0 I'm running xfs:

Writeback or writethrough?

Re: running iozone on bcache0 device yields wrongly read data

[Carsten Aulbert]

[-- Attachment #1: Type: text/plain, Size: 199 bytes --]

Hi

On 09/18/2013 06:45 AM, Kent Overstreet wrote:
> 
> Writeback or writethrough?
> 


Sorry, writeback as this testing is aimed for high performance scratch
space.

Cheers

Carsten


[-- Attachment #2: S/MIME Cryptographic Signature --]
[-- Type: application/pkcs7-signature, Size: 2044 bytes --]

Re: running iozone on bcache0 device yields wrongly read data

[Carsten Aulbert]

[-- Attachment #1: Type: text/plain, Size: 295 bytes --]

Hi again (sorry for the amount of small emails)

On 09/18/2013 08:42 AM, Carsten Aulbert wrote:
>> Writeback or writethrough?

> Sorry, writeback as this testing is aimed for high performance scratch
> space.
> 

Just  tested, the same happens with writethrough

Cheers

Carsten


[-- Attachment #2: S/MIME Cryptographic Signature --]
[-- Type: application/pkcs7-signature, Size: 2044 bytes --]

Re: running iozone on bcache0 device yields wrongly read data

[Kent Overstreet]

On Wed, Sep 18, 2013 at 10:43:52AM +0200, Carsten Aulbert wrote:
> Hi again (sorry for the amount of small emails)
> 
> On 09/18/2013 08:42 AM, Carsten Aulbert wrote:
> >> Writeback or writethrough?
> 
> > Sorry, writeback as this testing is aimed for high performance scratch
> > space.
> > 
> 
> Just  tested, the same happens with writethrough

Oh, damn. Can you check 3.10.9 and 3.10.10?

Re: running iozone on bcache0 device yields wrongly read data

[Carsten Aulbert]

[-- Attachment #1: Type: text/plain, Size: 248 bytes --]



On 09/18/2013 10:48 AM, Kent Overstreet wrote:
> Oh, damn. Can you check 3.10.9 and 3.10.10?
> 


Wilco - if I new hot to git bisect across various branches I'd do that
as well.

Time to learn :)

More soonish

Cheers

Carsten


[-- Attachment #2: S/MIME Cryptographic Signature --]
[-- Type: application/pkcs7-signature, Size: 2044 bytes --]

Re: running iozone on bcache0 device yields wrongly read data

[Carsten Aulbert]

[-- Attachment #1: Type: text/plain, Size: 738 bytes --]

Hi Kent (et al.)

On 09/18/2013 01:41 PM, Carsten Aulbert wrote:
> Wilco - if I new hot to git bisect across various branches I'd do that
> as well.
> 

I hit a bumpy road with bisectioning with kernels refusing to boot (not
finding their rootfs neither via UUID nor /dev/sd{a,b}) and we had a
large conference to run, so I failed to find any "bad" commit.

Also, it did not help, that I needed to get the test machine into
production use last week - now I need another test bed for testing.

Given that I used a 32GB SSD and the problems only ever occurred when
the iozone file size was close or exceeded the capacity of the cache
device, does this help you in guessing what I hit along the road?

Cheers

Carsten


[-- Attachment #2: S/MIME Cryptographic Signature --]
[-- Type: application/pkcs7-signature, Size: 2044 bytes --]