Bug 814926

Summary: [glusterfs-3.3.0qa35]: rpc errors and io-buf errors in the log file
Product: [Community] GlusterFS Reporter: Raghavendra Bhat <rabhat>
Component: coreAssignee: Amar Tumballi <amarts>
Status: CLOSED CURRENTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: high    
Version: mainlineCC: gluster-bugs, vraman
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: glusterfs-3.4.0 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-07-24 17:28:21 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: glusterfs-3.3.0qa40 Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 817967    

Description Raghavendra Bhat 2012-04-21 10:41:13 UTC 
Description of problem:
3 replica volume with 3 fuse and 3 nfs clients running different tests such as ping_pong, fs-perf-test, rdd, sanity tests, dbench, kernel compile etc.

On the server side there are many log messages indicating reply submission has been failed and io-buf has got the request for a page whose size is greater than the maxium page-size availabe.
3.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.304450] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.304488] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x126x, Program: GlusterFS 
3.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.304546] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.304583] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x124x, Program: GlusterFS 
3.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.304641] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.304679] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x95x, Program: GlusterFS 3
.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.304737] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.304775] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x94x, Program: GlusterFS 3
.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.304834] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.304871] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x93x, Program: GlusterFS 3
.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.304929] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.304973] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x92x, Program: GlusterFS 3
.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.305040] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed
[2012-04-19 20:58:28.305081] E [rpcsvc.c:1084:rpcsvc_submit_generic] 0-rpc-service: failed to submit message (XID: 0x91x, Program: GlusterFS 3
.3.0qa35, ProgVers: 330, Proc: 30) to rpc-transport (tcp.mirror-server)
[2012-04-19 20:58:28.305140] E [server.c:176:server_submit_reply] (-->/usr/local/lib/libglusterfs.so.0(default_finodelk_cbk+0x158) [0x7fbdeede
09bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/debug/io-stats.so(io_stats_finodelk_cbk+0x245) [0x7fbde97ea091] (-->/usr/local/lib/gluster
fs/3.3.0qa35/xlator/protocol/server.so(server_finodelk_cbk+0x30c) [0x7fbde95b45d4]))) 0-: Reply submission failed


io-buf related errors:

2012-04-19 20:58:36.395717] I [server-handshake.c:571:server_setvolume] 0-mirror-server: accepted client from gqas004.sbu.lab.eng.bos.redhat.com-31472-2012/04/19-20:58:31:372824-mirror-client-0-0 (version: 3.3.0qa35)
[2012-04-19 20:58:36.408274] E [server-helpers.c:763:server_alloc_frame] (-->/usr/local/lib/libgfrpc.so.0(rpcsvc_handle_rpc_call+0x360) [0x7fbdeebad102] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/protocol/server.so(server_lookup+0x162) [0x7fbde95cc4bf] (-->/usr/local/lib/glusterfs/3.3.0qa35/xlator/protocol/server.so(get_frame_from_request+0x89) [0x7fbde95b04ff]))) 0-server: invalid argument: conn
[2012-04-19 20:58:36.408520] I [server-handshake.c:571:server_setvolume] 0-mirror-server: accepted client from gqas006.sbu.lab.eng.bos.redhat.com-4702-2012/04/19-20:59:45:493500-mirror-client-0-0 (version: 3.3.0qa35)
[2012-04-19 20:58:36.410893] I [server-handshake.c:571:server_setvolume] 0-mirror-server: accepted client from gqas007.sbu.lab.eng.bos.redhat.com-22919-2012/04/19-21:03:43:792220-mirror-client-0-0 (version: 3.3.0qa35)
[2012-04-19 20:58:36.419970] I [server-handshake.c:571:server_setvolume] 0-mirror-server: accepted client from gqas004.sbu.lab.eng.bos.redhat.com-31478-2012/04/19-20:58:32:398152-mirror-client-0-0 (version: 3.3.0qa35)
[2012-04-19 21:16:35.332587] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:16:35.332656] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:16:35.332665] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:20:58.961296] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:20:58.961378] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:20:58.961401] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:25:23.817684] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:25:23.817764] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:25:23.817774] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:29:40.813214] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:29:40.813283] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:29:40.813293] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:33:58.610314] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:33:58.610394] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:33:58.610403] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:38:23.394107] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:38:23.394192] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:38:23.394203] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:42:49.817868] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:42:49.817938] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:42:49.817948] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:47:14.927247] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available
[2012-04-19 21:47:14.927324] E [glusterfsd-mgmt.c:84:glusterfs_serialize_reply] 0-glusterfs: Failed to get iobuf
[2012-04-19 21:47:14.927334] E [glusterfsd-mgmt.c:137:glusterfs_submit_reply] 0-glusterfs: Failed to serialize reply
[2012-04-19 21:51:40.501591] E [iobuf.c:526:iobuf_get2] 0-iobuf: page_size (2594464) of iobufs in arena being requested is greater than max available


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


How reproducible:


Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:


gluster volume info
 
Volume Name: mirror
Type: Replicate
Volume ID: 14c7c1cf-6711-4196-9c2b-27b6a38d19ae
Status: Started
Number of Bricks: 1 x 3 = 3
Transport-type: tcp
Bricks:
Brick1: 10.16.156.9:/export/mirror
Brick2: 10.16.156.12:/export/mirror
Brick3: 10.16.156.15:/export/mirror
Options Reconfigured:
performance.stat-prefetch: on
diagnostics.count-fop-hits: on
diagnostics.latency-measurement: on
performance.flush-behind: on


gluster volume status mirror
Status of volume: mirror
Gluster process                                         Port    Online  Pid
------------------------------------------------------------------------------
Brick 10.16.156.9:/export/mirror                        24009   Y       17325
Brick 10.16.156.12:/export/mirror                       24009   Y       15933
Brick 10.16.156.15:/export/mirror                       24009   Y       32327
NFS Server on localhost                                 38467   Y       31473
Self-heal Daemon on localhost                           N/A     Y       31479
NFS Server on 10.16.156.12                              38467   Y       15939
Self-heal Daemon on 10.16.156.12                        N/A     Y       15945
NFS Server on 10.16.156.15                              38467   Y       4697
Self-heal Daemon on 10.16.156.15                        N/A     Y       4703
NFS Server on 10.16.156.18                              38467   Y       22914
Self-heal Daemon on 10.16.156.18                        N/A     Y       22920
 
[root@gqas004 glusterfs-3.3.0qa35]#
Comment 1 Amar Tumballi 2012-04-23 04:39:09 UTC 
bug 812784 is logged to fix the iobuf bug. 

about the RPC submission failures, it is possible with a disconnect.
Comment 2 Anand Avati 2012-04-24 01:50:29 UTC 
CHANGE: http://review.gluster.com/3205 (glusterfsd: print entire path of functions whenever serializing a reply fails) merged in master by Anand Avati (avati)
Comment 3 Amar Tumballi 2012-05-04 05:08:44 UTC 
as bug 812784 also got fixed. moving this to ON_QA.
Comment 4 Raghavendra Bhat 2012-05-10 10:43:40 UTC 
Checked with glusterfs-3.3.0qa40. Such errors are not seen now.