Bug 1288202 - iobuf_unref errors killing logging
iobuf_unref errors killing logging
Status: CLOSED EOL
Product: GlusterFS
Classification: Community
Component: core (Show other bugs)
3.5.5
x86_64 Linux
unspecified Severity medium
: ---
: ---
Assigned To: Kaleb KEITHLEY
: Triaged
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-12-03 14:40 EST by Neil Van Lysel
Modified: 2016-06-17 12:23 EDT (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 1116514
Environment:
Last Closed: 2016-06-17 12:23:25 EDT
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)

  None (edit)
Description Neil Van Lysel 2015-12-03 14:40:42 EST
I'm running into this error with 3.5.5.
Client logs show:
[2015-11-20 20:26:25.268214] E [iobuf.c:733:iobuf_unref] (-->/usr/lib64/libglusterfs.so.0(call_resume+0x41f) [0x30bea3500f] (-->/usr/lib64/libglusterfs.so.0(default_readv_resume+0x15b) [0x30bea2497b] (-->/usr/lib64/glusterfs/3.5.5/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f03d0c3c4f2]))) 0-iobuf: invalid argument: iobuf
[2015-11-20 20:26:25.268256] E [iobuf.c:839:iobref_unref] (-->/usr/lib64/libglusterfs.so.0(call_resume+0x41f) [0x30bea3500f] (-->/usr/lib64/libglusterfs.so.0(default_readv_resume+0x15b) [0x30bea2497b] (-->/usr/lib64/glusterfs/3.5.5/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f03d0c3c4f2]))) 0-iobuf: invalid argument: iobref
[2015-11-20 22:17:37.622195] E [iobuf.c:733:iobuf_unref] (-->/usr/lib64/libglusterfs.so.0(call_resume+0x41f) [0x30bea3500f] (-->/usr/lib64/libglusterfs.so.0(default_readv_resume+0x15b) [0x30bea2497b] (-->/usr/lib64/glusterfs/3.5.5/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f03d0c3c4f2]))) 0-iobuf: invalid argument: iobuf
[2015-11-20 22:17:37.622237] E [iobuf.c:839:iobref_unref] (-->/usr/lib64/libglusterfs.so.0(call_resume+0x41f) [0x30bea3500f] (-->/usr/lib64/libglusterfs.so.0(default_readv_resume+0x15b) [0x30bea2497b] (-->/usr/lib64/glusterfs/3.5.5/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f03d0c3c4f2]))) 0-iobuf: invalid argument: iobref
[2015-11-20 22:20:43.491063] E [iobuf.c:733:iobuf_unref] (-->/usr/lib64/libglusterfs.so.0(call_resume+0x41f) [0x30bea3500f] (-->/usr/lib64/libglusterfs.so.0(default_readv_resume+0x15b) [0x30bea2497b] (-->/usr/lib64/glusterfs/3.5.5/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f03d0c3c4f2]))) 0-iobuf: invalid argument: iobuf
[2015-11-20 22:20:43.491104] E [iobuf.c:839:iobref_unref] (-->/usr/lib64/libglusterfs.so.0(call_resume+0x41f) [0x30bea3500f] (-->/usr/lib64/libglusterfs.so.0(default_readv_resume+0x15b) [0x30bea2497b] (-->/usr/lib64/glusterfs/3.5.5/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f03d0c3c4f2]))) 0-iobuf: invalid argument: iobref


Version-Release number of selected component (if applicable):

How reproducible:
often

Steps to Reproduce:
1. Create 8x2 distributed-replicate volume
2. Mount volume on client via fuse and write data to it using dd
  
Additional info:
[root@storage-1 ~]# gluster volume info
Volume Name: home
Type: Distributed-Replicate
Volume ID: 2694f438-08f6-48fc-a072-324d4701f112
Status: Started
Number of Bricks: 8 x 2 = 16
Transport-type: tcp
Bricks:
Brick1: storage-7:/brick1/home
Brick2: storage-8:/brick1/home
Brick3: storage-9:/brick1/home
Brick4: storage-10:/brick1/home
Brick5: storage-1:/brick1/home
Brick6: storage-2:/brick1/home
Brick7: storage-3:/brick1/home
Brick8: storage-4:/brick1/home
Brick9: storage-5:/brick1/home
Brick10: storage-6:/brick1/home
Brick11: storage-11:/brick1/home
Brick12: storage-12:/brick1/home
Brick13: storage-13:/brick1/home
Brick14: storage-14:/brick1/home
Brick15: storage-15:/brick1/home
Brick16: storage-16:/brick1/home
Options Reconfigured:
performance.cache-size: 100MB
performance.write-behind-window-size: 100MB
nfs.disable: on
features.quota: on
features.default-soft-limit: 90%


GLUSTER SERVER PACKAGES:
[root@storage-1 ~]# rpm -qa |grep gluster
glusterfs-cli-3.5.5-2.el6.x86_64
glusterfs-server-3.5.5-2.el6.x86_64
glusterfs-libs-3.5.5-2.el6.x86_64
glusterfs-fuse-3.5.5-2.el6.x86_64
glusterfs-3.5.5-2.el6.x86_64
glusterfs-api-3.5.5-2.el6.x86_64


GLUSTER CLIENT PACKAGES:
[root@client-1 ~]# rpm -qa |grep gluster
glusterfs-api-3.5.5-2.el6.x86_64
glusterfs-libs-3.5.5-2.el6.x86_64
glusterfs-fuse-3.5.5-2.el6.x86_64
glusterfs-3.5.5-2.el6.x86_64





+++ This bug was initially created as a clone of Bug #1116514 +++

After starting the client, a rapid sequence of these errors results in the last entry never being fully written an the log never goes any further.

After a couple of days, this client is dying but I have no idea why as there's no log beyond where it halts.

[root@mysql1 glusterfs]# tail -n 5 /var/log/glusterfs/mnt-gluster-mysql1.log
[2014-07-05 15:00:02.238570] E [iobuf.c:733:iobuf_unref] (-->/usr/lib64/glusterfs/3.4.4/xlator/debug/io-stats.so(io_stats_readv+0x17d) [0x7f028b5bec3d] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/md-cache.so(mdc_readv+0x166) [0x7f028b7d36c6] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f028b9e0492]))) 0-iobuf: invalid argument: iobuf
[2014-07-05 15:00:02.238613] E [iobuf.c:828:iobref_unref] (-->/usr/lib64/glusterfs/3.4.4/xlator/debug/io-stats.so(io_stats_readv+0x17d) [0x7f028b5bec3d] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/md-cache.so(mdc_readv+0x166) [0x7f028b7d36c6] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f028b9e0492]))) 0-iobuf: invalid argument: iobref
[2014-07-05 15:00:02.243550] E [iobuf.c:733:iobuf_unref] (-->/usr/lib64/glusterfs/3.4.4/xlator/debug/io-stats.so(io_stats_readv+0x17d) [0x7f028b5bec3d] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/md-cache.so(mdc_readv+0x166) [0x7f028b7d36c6] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f028b9e0492]))) 0-iobuf: invalid argument: iobuf
[2014-07-05 15:00:02.243594] E [iobuf.c:828:iobref_unref] (-->/usr/lib64/glusterfs/3.4.4/xlator/debug/io-stats.so(io_stats_readv+0x17d) [0x7f028b5bec3d] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/md-cache.so(mdc_readv+0x166) [0x7f028b7d36c6] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/quick-read.so(qr_readv+0x62) [0x7f028b9e0492]))) 0-iobuf: invalid argument: iobref
[2014-07-05 15:00:02.295156] E [iobuf.c:733:iobuf_unref] (-->/usr/lib64/glusterfs/3.4.4/xlator/debug/io-stats.so(io_stats_readv+0x17d) [0x7f028b5bec3d] (-->/usr/lib64/glusterfs/3.4.4/xlator/performance/md-cache.so(mdc_readv+0x166) [0x7f028b7d36c6] (-->/usr/lib64/glusterfs/3.4.4/xlator/pe[root@mysql1 glusterfs]# 

Version-Release number of selected component (if applicable):
3.4.4-2

Volume Name: mysql1
Type: Distributed-Replicate
Volume ID: 713e6220-7eb2-4d12-9cd7-fe800b9b741a
Status: Started
Number of Bricks: 4 x 3 = 12
Transport-type: tcp
Bricks:
Brick1: ewcs2:/var/spool/glusterfs/a_mysql1
Brick2: ewcs10:/data/glusterfs/mysql1/a/brick
Brick3: ewcs7:/data/glusterfs/mysql1/a/brick
Brick4: ewcs2:/var/spool/glusterfs/b_mysql1
Brick5: ewcs10:/data/glusterfs/mysql1/b/brick
Brick6: ewcs7:/data/glusterfs/mysql1/b/brick
Brick7: ewcs2:/var/spool/glusterfs/c_mysql1
Brick8: ewcs10:/data/glusterfs/mysql1/c/brick
Brick9: ewcs7:/data/glusterfs/mysql1/c/brick
Brick10: ewcs2:/data/glusterfs/mysql1/d/brick
Brick11: ewcs10:/data/glusterfs/mysql1/d/brick
Brick12: ewcs7:/data/glusterfs/mysql1/d/brick
Options Reconfigured:
server.allow-insecure: on
performance.write-behind: off
nfs.disable: on
performance.cache-size: 8MB
cluster.background-self-heal-count: 2
cluster.data-self-heal-algorithm: full

--- Additional comment from Anand Avati on 2014-07-05 11:54:17 EDT ---

REVIEW: http://review.gluster.org/8242 (performance/quick-read: Check for iobuf and iobref before unref.) posted (#1) for review on release-3.4 by Vijay Bellur (vbellur@redhat.com)

--- Additional comment from Anand Avati on 2014-07-08 07:52:24 EDT ---

COMMIT: http://review.gluster.org/8242 committed in release-3.4 by Kaleb KEITHLEY (kkeithle@redhat.com) 
------
commit b3bf2cfaa8e932f02a10a42e0281290a7cbdc960
Author: Vijay Bellur <vbellur@redhat.com>
Date:   Sat Jul 5 21:19:01 2014 +0530

    performance/quick-read: Check for iobuf and iobref before unref.
    
    In the absence of this check, iobuf_unref() can cause a log flood
    for read operations.
    
    Change-Id: Ib8beef6e55b69ecfb566bf61a96215ef0d0d74dc
    BUG: 1116514
    Signed-off-by: Vijay Bellur <vbellur@redhat.com>
    Reviewed-on: http://review.gluster.org/8242
    Tested-by: Gluster Build System <jenkins@build.gluster.com>
    Reviewed-by: Humble Devassy Chirammal <humble.devassy@gmail.com>
    Reviewed-by: Prashanth Pai <ppai@redhat.com>
    Reviewed-by: Kaleb KEITHLEY <kkeithle@redhat.com>
Comment 1 Niels de Vos 2016-06-17 12:23:25 EDT
This bug is getting closed because the 3.5 is marked End-Of-Life. There will be no further updates to this version. Please open a new bug against a version that still receives bugfixes if you are still facing this issue in a more current release.

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