Bug#684364: target: reports vfs_writev() returned -28 on iscsi activity
Hello, problem hit again kernel is ii linux-image-3.2.0-3-amd643.2.23-1amd64 Linux 3.2 for 64-bit PCs During backup to iscsi file located on btrfs, btrfs runs out of space vfs_writev() returned -28 # btrfs filesystem show --all-devices /dev/sdb failed to read /dev/sr0: No medium found failed to read /dev/fd0: No such device or address Label: none uuid: b99c5f6a-dce2-4ba5-9fc1-4394847f45be Total devices 1 FS bytes used 620.12GB devid1 size 635.00GB used 635.00GB path /dev/sdb Btrfs Btrfs v0.19 #btrfs filesystem df /mnt/tmp Data: total=626.77GB, used=617.32GB System, DUP: total=8.00MB, used=84.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=4.11GB, used=2.80GB #df /dev/sdb 665845760 653174560 9905632 99% /mnt/tmp #du -cms /mnt/tmp/iscsi/* 51201 /mnt/tmp/iscsi/iscsiCallCentrum 562575 /mnt/tmp/iscsi/iscsiSBS #mount /dev/sdb on /mnt/tmp type btrfs (rw,noatime,compress=lzo,nospace_cache) With regards Libor signature.asc Description: This is a digitally signed message part.
Bug#684364: target: reports vfs_writev() returned -28 on iscsi activity
Hello, Dne Sunday 12 August 2012 23:09:35, Ben Hutchings napsal(a): On Thu, 2012-08-09 at 09:40 +0200, root wrote: Package: linux-image-3.2.0-3-amd64 Version: 3.2.21-3 Severity: normal Hello, i'm using this virtual machine to export iscsi targets for windows machines to backup. It has 620GB btrfs partition with 550GB iscsi file_io LUN exported. I'm using btrfs snapshots to transport (consistent copy of) this big file to secondary backup storage (qnap and usb disk) - it takes around 12 hours to transport - thats reason to use snapshots. Everything was working fine, until i run out of space on btrfs (because of snapshot and fullbackup from windows combination). Since than, i have created fresh filesystem and create empty new file to export over iscsi. Now, around 250GB of writen data do iscsi file, kern.log starts to fill with these messages vfs_writev() returned -28 It keeps to show on every access to iscsi (even rescan disk operation in windows triggers it) Any read access may change the image file's access time (atime) if you don't use the 'noatime' mount option. On btrfs, metadata changes may allocate more disk space. You are right, i forgot noatime option on mount I was suspecting btrfs, but there is no oops in kern.log. I tried to google this error and found nothing relevant. Error 28 is ENOSPC: No space left on device. I tried to reset everything (new filesystem, empty file, remove/add target from windows) and this errors comes back after writing approx. 250GB of data. (Before problem, file was filled to around 540GB). Size now: # du -cms iscsiSBS 244561 iscsiSBS [...] What does 'btrfs filesystem df /btrfs' say (substitute the actual mountpoint for the btrfs volume)? It said (i saved this before running balance) Data: total=578.01GB, used=263.03GB System, DUP: total=8.00MB, used=72.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=1.73GB, used=1.03GB Metadata: total=8.00MB, used=0.00 I tried this - is it ok, it doesn't free used after rm? # dd if=/dev/zero of=/mnt/tmp/1 bs=100M count=10 # rm /mnt/tmp/1 # btrfs filesystem df /mnt/tmp/ Data: total=1.01GB, used=0.00 System, DUP: total=8.00MB, used=4.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=1.00GB, used=1.27MB Metadata: total=8.00MB, used=0.00 # dd if=/mnt/backupWin/iscsi/iscsiSBS of=/mnt/tmp/1 bs=100M count=10 10+0 records in 10+0 records out 1048576000 bytes (1.0 GB) copied, 22.0851 s, 47.5 MB/s # btrfs filesystem df /mnt/tmp/ Data: total=1.01GB, used=1000.00MB System, DUP: total=8.00MB, used=4.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=1.00GB, used=1.41MB Metadata: total=8.00MB, used=0.00 # rm /mnt/tmp/1 # btrfs filesystem df /mnt/tmp/ Data: total=1.01GB, used=1000.00MB System, DUP: total=8.00MB, used=4.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=1.00GB, used=1.41MB Metadata: total=8.00MB, used=0.00 # dd if=/mnt/backupWin/iscsi/iscsiSBS of=/mnt/tmp/1 bs=100M count=90 dd: writing `/mnt/tmp/1': No space left on device 82+0 records in 81+0 records out 8560574464 bytes (8.6 GB) copied, 280.973 s, 30.5 MB/s # btrfs filesystem df /mnt/tmp/ Data: total=7.97GB, used=7.97GB System, DUP: total=8.00MB, used=4.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=1.00GB, used=11.39MB Metadata: total=8.00MB, used=0.00 # rm /mnt/tmp/1 # btrfs filesystem df /mnt/tmp/ Data: total=7.97GB, used=5.65GB System, DUP: total=8.00MB, used=4.00KB System: total=4.00MB, used=0.00 Metadata, DUP: total=1.00GB, used=8.06MB Metadata: total=8.00MB, used=0.00 Ben. Libor signature.asc Description: This is a digitally signed message part.
Bug#684364: target: reports vfs_writev() returned -28 on iscsi activity
Hello, i have just noticed oops, which happend during experiments this morning Libor [141443.054425] btrfs: block rsv returned -28 [141443.054428] [ cut here ] [141443.054466] WARNING: at /build/buildd-linux_3.2.21-3-amd64- l_qIBB/linux-3.2.21/fs/btrfs/extent-tree.c:5985 btrfs_alloc_free_block+0xd7/0x284 [btrfs]() [141443.054470] Hardware name: VMware Virtual Platform [141443.054472] Modules linked in: autofs4 tcm_loop tcm_fc iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod des_generic ecb md4 hmac nls_utf8 cifs libfc scsi_transport_fc scsi_tgt configfs vmsync(O) vmhgfs(O) nfsd nfs nfs_acl auth_rpcgss fscache lockd sunrpc dm_multipath scsi_dh loop coretemp crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 parport_pc joydev parport usbhid snd_pcm snd_page_alloc snd_timer snd vmw_balloon soundcore hid aes_generic cryptd psmouse serio_raw pcspkr processor ac evdev power_supply thermal_sys i2c_piix4 i2c_core container shpchp vmci(O) button ext4 crc16 jbd2 mbcache btrfs crc32c libcrc32c zlib_deflate dm_mod sr_mod cdrom ata_generic sd_mod crc_t10dif uhci_hcd floppy ehci_hcd usbcore usb_common e1000 ata_piix mptspi scsi_transport_spi mptscsih mptbase libata scsi_mod [last unloaded: autofs4] [141443.054526] Pid: 28983, comm: btrfs-transacti Tainted: G O 3.2.0-3-amd64 #1 [141443.054529] Call Trace: [141443.054537] [81046901] ? warn_slowpath_common+0x78/0x8c [141443.054550] [a01441fe] ? btrfs_alloc_free_block+0xd7/0x284 [btrfs] [141443.054566] [a01690fe] ? read_extent_buffer+0x94/0xed [btrfs] [141443.054575] [a01377bf] ? __btrfs_cow_block+0x102/0x33a [btrfs] [141443.054585] [a0137aee] ? btrfs_cow_block+0xf7/0x143 [btrfs] [141443.054595] [a013a546] ? btrfs_search_slot+0x225/0x64e [btrfs] [141443.054608] [a0148750] ? btrfs_del_csums+0xc8/0x252 [btrfs] [141443.054618] [a013ff9c] ? __btrfs_free_extent+0x54f/0x5c8 [btrfs] [141443.054630] [a0142fc9] ? run_clustered_refs+0x65e/0x6aa [btrfs] [141443.054642] [a01430de] ? btrfs_run_delayed_refs+0xc9/0x176 [btrfs] [141443.054647] [8134a0a0] ? mutex_lock+0xd/0x2d [141443.054661] [a0150153] ? btrfs_commit_transaction+0x8f/0x6f9 [btrfs] [141443.054667] [8105f5f3] ? add_wait_queue+0x3c/0x3c [141443.054679] [a014faba] ? join_transaction.isra.24+0x5a/0x1f3 [btrfs] [141443.054692] [a0150bd5] ? start_transaction+0x1ed/0x242 [btrfs] [141443.054705] [a014a7ad] ? transaction_kthread+0x156/0x20f [btrfs] [141443.054717] [a014a657] ? btrfs_congested_fn+0x7b/0x7b [btrfs] [141443.054720] [8105efad] ? kthread+0x76/0x7e [141443.054725] [81351cf4] ? kernel_thread_helper+0x4/0x10 [141443.054729] [8105ef37] ? kthread_worker_fn+0x139/0x139 [141443.054732] [81351cf0] ? gs_change+0x13/0x13 [141443.054734] ---[ end trace 2684d70a838e2d6c ]--- signature.asc Description: This is a digitally signed message part.
Bug#684364: target: reports vfs_writev() returned -28 on iscsi activity
On Thu, 2012-08-09 at 09:40 +0200, root wrote: Package: linux-image-3.2.0-3-amd64 Version: 3.2.21-3 Severity: normal Hello, i'm using this virtual machine to export iscsi targets for windows machines to backup. It has 620GB btrfs partition with 550GB iscsi file_io LUN exported. I'm using btrfs snapshots to transport (consistent copy of) this big file to secondary backup storage (qnap and usb disk) - it takes around 12 hours to transport - thats reason to use snapshots. Everything was working fine, until i run out of space on btrfs (because of snapshot and fullbackup from windows combination). Since than, i have created fresh filesystem and create empty new file to export over iscsi. Now, around 250GB of writen data do iscsi file, kern.log starts to fill with these messages vfs_writev() returned -28 It keeps to show on every access to iscsi (even rescan disk operation in windows triggers it) Any read access may change the image file's access time (atime) if you don't use the 'noatime' mount option. On btrfs, metadata changes may allocate more disk space. I was suspecting btrfs, but there is no oops in kern.log. I tried to google this error and found nothing relevant. Error 28 is ENOSPC: No space left on device. I tried to reset everything (new filesystem, empty file, remove/add target from windows) and this errors comes back after writing approx. 250GB of data. (Before problem, file was filled to around 540GB). Size now: # du -cms iscsiSBS 244561 iscsiSBS [...] What does 'btrfs filesystem df /btrfs' say (substitute the actual mountpoint for the btrfs volume)? Ben. -- Ben Hutchings Sturgeon's Law: Ninety percent of everything is crap. signature.asc Description: This is a digitally signed message part
Bug#684364: target: reports vfs_writev() returned -28 on iscsi activity
Package: linux-image-3.2.0-3-amd64 Version: 3.2.21-3 Severity: normal Hello, i'm using this virtual machine to export iscsi targets for windows machines to backup. It has 620GB btrfs partition with 550GB iscsi file_io LUN exported. I'm using btrfs snapshots to transport (consistent copy of) this big file to secondary backup storage (qnap and usb disk) - it takes around 12 hours to transport - thats reason to use snapshots. Everything was working fine, until i run out of space on btrfs (because of snapshot and fullbackup from windows combination). Since than, i have created fresh filesystem and create empty new file to export over iscsi. Now, around 250GB of writen data do iscsi file, kern.log starts to fill with these messages vfs_writev() returned -28 It keeps to show on every access to iscsi (even rescan disk operation in windows triggers it) I was suspecting btrfs, but there is no oops in kern.log. I tried to google this error and found nothing relevant. I tried to reset everything (new filesystem, empty file, remove/add target from windows) and this errors comes back after writing approx. 250GB of data. (Before problem, file was filled to around 540GB). Size now: # du -cms iscsiSBS 244561 iscsiSBS Output of 'find /lib/modules/ | xargs strings | grep vfs_writev() returned' shows only one line, which is in target_core_file.ko With regards Libor -- Package-specific info: ** Version: Linux version 3.2.0-3-amd64 (Debian 3.2.21-3) (debian-kernel@lists.debian.org) (gcc version 4.6.3 (Debian 4.6.3-8) ) #1 SMP Thu Jun 28 09:07:26 UTC 2012 ** Command line: BOOT_IMAGE=/boot/vmlinuz-3.2.0-3-amd64 root=/dev/mapper/vgDisk1-lvSystem ro quiet ** Tainted: O (4096) * Out-of-tree module has been loaded. ** Kernel log: [77575.095989] vfs_writev() returned -28 [77575.096650] vfs_writev() returned -28 [77575.097270] vfs_writev() returned -28 [77576.594098] vfs_writev() returned -28 [77580.197458] vfs_writev() returned -28 [77580.198214] vfs_writev() returned -28 [77585.345379] vfs_writev() returned -28 [77585.346186] vfs_writev() returned -28 [77585.346892] vfs_writev() returned -28 [77585.347642] vfs_writev() returned -28 ** Model information sys_vendor: VMware, Inc. product_name: VMware Virtual Platform product_version: None chassis_vendor: No Enclosure chassis_version: N/A bios_vendor: Phoenix Technologies LTD bios_version: 6.00 board_vendor: Intel Corporation board_name: 440BX Desktop Reference Platform board_version: None ** Loaded modules: des_generic ecb md4 hmac nls_utf8 cifs autofs4 nfnetlink_log nfnetlink tcm_loop tcm_fc iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod libfc scsi_transport_fc scsi_tgt configfs vmsync(O) vmhgfs(O) nfsd nfs nfs_acl auth_rpcgss fscache lockd sunrpc dm_round_robin dm_multipath scsi_dh loop joydev usbhid hid ses enclosure coretemp crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 aes_generic psmouse snd_pcm snd_page_alloc snd_timer snd parport_pc parport soundcore vmw_balloon evdev cryptd i2c_piix4 ac serio_raw pcspkr i2c_core shpchp power_supply vmci(O) processor container thermal_sys button ext4 crc16 jbd2 mbcache btrfs crc32c libcrc32c zlib_deflate usb_storage uas dm_mod sd_mod crc_t10dif uhci_hcd sr_mod cdrom mptspi scsi_transport_spi mptscsih ata_generic floppy mptbase ehci_hcd usbcore ata_piix usb_common e1000 libata scsi_mod ** Network interface configuration: auto lo iface lo inet loopback allow-hotplug eth0 iface eth0 inet static address 192.168.5.213 netmask 255.255.255.0 network 192.168.5.0 broadcast 192.168.5.255 ** Network status: *** IP interfaces and addresses: 1: lo: LOOPBACK,UP,LOWER_UP mtu 16436 qdisc noqueue state UNKNOWN link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo inet6 ::1/128 scope host valid_lft forever preferred_lft forever 2: eth0: BROADCAST,MULTICAST,UP,LOWER_UP mtu 1500 qdisc pfifo_fast state UP qlen 1000 link/ether 00:0c:29:59:fe:c9 brd ff:ff:ff:ff:ff:ff inet 192.168.5.213/24 brd 192.168.5.255 scope global eth0 inet6 fe80::20c:29ff:fe59:fec9/64 scope link valid_lft forever preferred_lft forever *** Device statistics: Inter-| Receive| Transmit face |bytespackets errs drop fifo frame compressed multicast|bytes packets errs drop fifo colls carrier compressed lo: 87464948 10977000 0 0 0 87464948 10977000 0 0 0 eth0: 287037645968 1972852590 240 0 0 0 8008550193 22837748000 0 0 0 *** Protocol statistics: Ip: 13169750 total packets received 0 forwarded 0 incoming packets discarded 13165208 incoming packets delivered 21135011 requests sent out 5992 reassemblies required 1498 packets reassembled ok Icmp: 1803 ICMP messages received 0 input ICMP
