Description of problem: when glusterd is restarted on the node from which volume is mounted on the client, IO fails on the mountpoint. 'Transport endpoint is not connected' error is seen. Version-Release number of selected component (if applicable): rpm -qa | grep 'gluster' glusterfs-resource-agents-3.10.0rc-0.0.el7.centos.noarch glusterfs-events-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-debuginfo-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-api-3.10.0rc-0.0.el7.centos.x86_64 python2-gluster-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-fuse-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-server-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-devel-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-api-devel-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-geo-replication-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-libs-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-client-xlators-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-extra-xlators-3.10.0rc-0.0.el7.centos.x86_64 glusterfs-cli-3.10.0rc-0.0.el7.centos.x86_64 How reproducible: always Steps to Reproduce: 1. on a 3 node gluster cluster, set cluster.brick-multiplex on 2. create a 2x3 volume 3. mount the volume and run IO 4. restart glusterd on the node from which volume is mounted 5. check if IO continues from the client Actual results: Transport endpoint not connected error is seen and IO halts Expected results: IO should continue and glusterd restart should not affect client IOs Additional info: No logs shall be attached as this is easily reproducible, let me know if sosreports are needed
This is reproducible locally as well. client log indicates that client process is shutdown. Something is wrong in the reconnect logic. [2017-02-16 10:21:29.026311] E [timer.c:44:gf_timer_call_after] (-->/usr/local/lib/libgfrpc.so.0(rpc_transport_notify+0x23) [0x7fe5ffce4223] -->/usr/local/lib/libgfrpc.so.0(rpc_clnt_notify+0x2b0) [0x7fe5ffce7ca0] -->/usr/local/lib/ libglusterfs.so.0(gf_timer_call_after+0x2a9) [0x7fe5fff293c9] ) 0-timer: !reg [2017-02-16 10:21:29.026317] W [rpc-clnt.c:893:rpc_clnt_handle_disconnect] 0-test-vol-client-0: Cannot create rpc_clnt_reconnect timer [2017-02-16 10:21:29.026322] I [MSGID: 114018] [client.c:2276:client_rpc_notify] 0-test-vol-client-0: disconnected from test-vol-client-0. Client process will keep trying to connect to glusterd until brick's port is available [2017-02-16 10:21:29.030938] W [glusterfsd.c:1329:cleanup_and_exit] (-->/lib64/libpthread.so.0(+0x75ba) [0x7fe5fed775ba] -->/usr/local/sbin/glusterfs(glusterfs_sigwaiter+0xc5) [0x408615] -->/usr/local/sbin/ glusterfs(cleanup_and_exit+0x4b) [0x4084ab] ) 0-: received signum (15), shutting down
Setting priority as medium because GlusterD restarting while bricks continue to run is not a common case either as an administrative action or as a failure event.
REVIEW: https://review.gluster.org/16665 (tests: add test for restarting glusterd with I/O ongoing) posted (#1) for review on master by Jeff Darcy (jdarcy)
Test is here: https://review.gluster.org/#/c/16665/ Still no errors. What's missing?
Jeff, I was able to reproduce it with a 2x3 volume on a 3 node cluster.
Great. I'll try to rearrange the test script to use the cluster.rc stuff, and see if that's sufficient.
Still no luck. How much I/O are you doing? If it's some sort of a race that has to be hit in the middle of a fop, maybe the script just isn't doing enough. If that's not it, we might need to start looking at differences in how things are being built, because we're running out of other possibilities. Having to test on a physical three-node cluster is going to slow things down a lot, especially if it has to be manual, and it doesn't allow for verification through our regression-test infrastructure.
Also, when you talk about three nodes are you talking physical machines, virtual machines, or containers? Could there be an environment-specific aspect to this?
(In reply to Jeff Darcy from comment #8) > Also, when you talk about three nodes are you talking physical machines, > virtual machines, or containers? Could there be an environment-specific > aspect to this? Sorry, I wanted to try this out with the latest build before replying to the questions. I'm still seeing this issue quite consistently with the latest build too. I'm using gluster containers for my testing. I'll attach the logs shortly.
snippet of client log: 2017-03-02 04:00:17.481864] D [write-behind.c:380:__wb_request_unref] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x13b)[0x7fac5d51fddb] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/performance/write-behind.s o(+0x2582)[0x7fac55a6d582] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/performance/write-behind.so(+0x6857)[0x7fac55a71857] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/performance/write-behind.so(+0x6b88)[0x7fac55 a71b88] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/performance/write-behind.so(+0x8b5f)[0x7fac55a73b5f] ))))) 0-vol1-write-behind: (unique = 681, fop=WRITE, gfid=d0eb059e-f1e9-497f-b325-08e21de9ceb7, gen=7): des troying request, removing from all queues [2017-03-02 04:00:17.482039] D [write-behind.c:1695:wb_process_queue] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x13b)[0x7fac5d51fddb] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/performance/write-behind.so (+0x8acb)[0x7fac55a73acb] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/performance/write-behind.so(+0x8b67)[0x7fac55a73b67] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/cluster/distribute.so(+0x5b32a)[0x7fac55cda32a ] (--> /usr/lib64/glusterfs/3.10.0rc0/xlator/cluster/replicate.so(+0x220e2)[0x7fac55f2b0e2] ))))) 0-vol1-write-behind: processing queues [2017-03-02 04:00:17.488751] D [socket.c:562:__socket_rwv] 0-glusterfs: EOF on socket [2017-03-02 04:00:17.488771] W [socket.c:593:__socket_rwv] 0-glusterfs: readv on 10.70.46.80:24007 failed (No data available) [2017-03-02 04:00:17.488782] D [socket.c:2404:socket_event_handler] 0-transport: disconnecting now [2017-03-02 04:00:17.488920] D [rpc-clnt-ping.c:93:rpc_clnt_remove_ping_timer_locked] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x13b)[0x7fac5d51fddb] (--> /lib64/libgfrpc.so.0(rpc_clnt_remove_ping_timer_l ocked+0x8e)[0x7fac5d2ebcce] (--> /lib64/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x5b)[0x7fac5d2e80fb] (--> /lib64/libgfrpc.so.0(rpc_clnt_notify+0x8c)[0x7fac5d2e89ac] (--> /lib64/libgfrpc.so.0(rpc_transport_not ify+0x23)[0x7fac5d2e49e3] ))))) 0-: 10.70.46.80:24007: ping timer event already removed [2017-03-02 04:00:17.488943] E [glusterfsd-mgmt.c:2102:mgmt_rpc_notify] 0-glusterfsd-mgmt: failed to connect with remote-host: 10.70.46.80 (No data available) [2017-03-02 04:00:17.488950] I [glusterfsd-mgmt.c:2120:mgmt_rpc_notify] 0-glusterfsd-mgmt: Exhausted all volfile servers [2017-03-02 04:00:17.488955] D [logging.c:1764:gf_log_flush_extra_msgs] 0-logging-infra: Log buffer size reduced. About to flush 5 extra log messages [2017-03-02 04:00:17.488964] D [logging.c:1767:gf_log_flush_extra_msgs] 0-logging-infra: Just flushed 5 extra log messages [2017-03-02 04:00:17.488993] W [glusterfsd.c:1329:cleanup_and_exit] (-->/lib64/libgfrpc.so.0(rpc_clnt_notify+0xd3) [0x7fac5d2e89f3] -->/usr/sbin/glusterfs(+0x10a9f) [0x7fac5da1ea9f] -->/usr/sbin/glusterfs(cleanu p_and_exit+0x6b) [0x7fac5da17dfb] ) 0-: received signum (1), shutting down [2017-03-02 04:00:17.489002] D [glusterfsd-mgmt.c:2577:glusterfs_mgmt_pmap_signout] 0-fsd-mgmt: portmapper signout arguments not given [2017-03-02 04:00:17.489009] I [fuse-bridge.c:5802:fini] 0-fuse: Unmounting '/mnt/krk1'.
Jeff, I was able to hit this issue again. Here is how the volume status looks like: root@15e82395bcbc:/home/glusterfs# gluster v status Status of volume: test-vol Gluster process TCP Port RDMA Port Online Pid ------------------------------------------------------------------------------ Brick 172.17.0.2:/tmp/b1 49152 0 Y 25014 Brick 172.17.0.3:/tmp/b1 49154 0 Y 1727 Brick 172.17.0.4:/tmp/b1 49154 0 Y 20966 Brick 172.17.0.2:/tmp/b2 49152 0 Y 25014 Brick 172.17.0.3:/tmp/b2 49154 0 Y 1727 Brick 172.17.0.4:/tmp/b2 49154 0 Y 20966 Self-heal Daemon on localhost N/A N/A N N/A Self-heal Daemon on 172.17.0.3 N/A N/A Y 1759 Self-heal Daemon on 172.17.0.4 N/A N/A Y 20998 Task Status of Volume test-vol ------------------------------------------------------------------------------ There are no active volume tasks When I mount the client in 172.17.0.2 and ran touch f{1..100000} and kill glusterd on the same node mount started throwing "Transport endpoint is not connected" errors for all the files. Mount log shows the following: [2017-03-06 13:49:36.437709] I [fuse-bridge.c:5802:fini] 0-fuse: Unmounting '/mnt/test-vol-mnt'. [2017-03-06 13:49:36.442986] W [socket.c:593:__socket_rwv] 0-test-vol-client-3: readv on 172.17.0.2:49154 failed (Connection reset by peer) [2017-03-06 13:49:36.443247] E [rpc-clnt.c:365:saved_frames_unwind] (--> /usr/local/lib/libglusterfs.so. 0(_gf_log_callingfn+0x12a)[0x7faa629c4a0a] (--> /usr/local/lib/libgfrpc.so.0(saved_frames_unwind+ 0x1b5)[0x7faa6278bd05] (--> /usr/local/lib/libgfrpc.so.0(saved_frames_destroy+0xe)[0x7faa6278bdfe] (--> /usr/local/ lib/libgfrpc.so.0(rpc_clnt_connection_cleanup+0x89)[0x7faa6278d379] (--> /usr/local/lib/libgfrpc.so. 0(rpc_clnt_notify+0x84)[0x7faa6278dc04] ))))) 0-test-vol-client-3: forced unwinding frame type(GlusterFS 3.3) op(CREATE(23)) called at 2017-03-06 13:49:36.440699 (xid=0x268a) [2017-03-06 13:49:36.443264] W [MSGID: 114031] [client-rpc-fops.c:2332:client3_3_create_cbk] 0-test-vol-client-3: remote operation failed. Path: /f1244 [Transport endpoint is not connected] [2017-03-06 13:49:36.446152] I [socket.c:3476:socket_submit_request] 0-test-vol-client-3: not connected (priv- >connected = 0) [2017-03-06 13:49:36.446170] W [rpc-clnt.c:1656:rpc_clnt_submit] 0-test-vol-client-3: failed to submit rpc-request (XID: 0x268b Program: GlusterFS 3.3, ProgVers: 330, Proc: 33) to rpc-transport (test-vol-client-3) [2017-03-06 13:49:36.446183] E [MSGID: 114031] [client-rpc-fops.c:1758:client3_3_xattrop_cbk] 0-test-vol-client-3: remote operation failed. Path: / (00000000-0000-0000-0000-000000000001) [2017-03-06 13:49:36.446249] I [timer.c:198:gf_timer_registry_init] (-->/usr/local/lib/libgfrpc.so. 0(rpc_transport_notify+0x23) [0x7faa6278a3b3] -->/usr/local/lib/libgfrpc.so.0(rpc_clnt_notify+0x2b0) [0x7faa6278de30] -->/usr/local/lib/libglusterfs.so.0(gf_timer_call_after+0x265) [0x7faa629cf3b5] ) 0-timer: ctx cleanup started [2017-03-06 13:49:36.446283] E [timer.c:44:gf_timer_call_after] (-->/usr/local/lib/libgfrpc.so. 0(rpc_transport_notify+0x23) [0x7faa6278a3b3] -->/usr/local/lib/libgfrpc.so.0(rpc_clnt_notify+0x2b0) [0x7faa6278de30] -->/usr/local/lib/libglusterfs.so.0(gf_timer_call_after+0x2a9) [0x7faa629cf3f9] ) 0-timer: !reg [2017-03-06 13:49:36.446289] W [rpc-clnt.c:893:rpc_clnt_handle_disconnect] 0-test-vol-client-3: Cannot create rpc_clnt_reconnect timer [2017-03-06 13:49:36.446296] I [MSGID: 114018] [client.c:2276:client_rpc_notify] 0-test-vol-client-3: disconnected from test-vol-client-3. Client process will keep trying to connect to glusterd until brick's port is available [2017-03-06 13:49:36.446575] E [MSGID: 114031] [client-rpc-fops.c:1646:client3_3_entrylk_cbk] 0-test-vol-client-3: remote operation failed [Transport endpoint is not connected] [2017-03-06 13:49:36.446593] E [MSGID: 108007] [afr-lk-common.c:825:afr_unlock_entrylk_cbk] 0-test-vol-replicate-1: /f1244: unlock failed on test-vol-client-3 [Transport endpoint is not connected] [2017-03-06 13:49:36.457023] W [glusterfsd.c:1329:cleanup_and_exit] (-->/lib64/libpthread.so.0(+0x75ba) [0x7faa6181d5ba] -->/usr/local/sbin/glusterfs(glusterfs_sigwaiter+0xc5) [0x408615] -->/usr/local/sbin/ glusterfs(cleanup_and_exit+0x4b) [0x4084ab] ) 0-: received signum (15), shutting down [2017-03-06 13:49:36.457023] W [glusterfsd.c:1329:cleanup_and_exit] (-->/lib64/libpthread.so.0(+0x75ba) [0x7faa6181d5ba] -->/usr/local/sbin/glusterfs(glusterfs_sigwaiter+0xc5) [0x408615] -->/usr/local/sbin/ glusterfs(cleanup_and_exit+0x4b) [0x4084ab] ) 0-: received signum (15), shutting down
The key is probably "Exhausted all volfile servers" from comment 10. This code is reused on clients, bricks, and (I think) auxiliary daemons - i.e. everywhere but glusterd and pure gfapi clients. Perhaps that's a bad idea, because those things do have different needs. In this case, while it's semi-appropriate to have a brick daemon give up at this point, it's just as clearly the wrong thing to do for clients. I've reverted the change to this behavior, which was made as part of the multiplexing patch. This should fix the immediate problem, though it's hard to verify whether there might still be others because I still haven't been able to reproduce the problem on a normal configuration. Also, there's a pretty high chance that the revert will re-introduce whatever problem the change was originally made to fix. I doubt that it was changed for no reason, but I don't recall which specific test was failing before. I guess we'll find out. ;)
REVIEW: https://review.gluster.org/16866 (glusterfsd: don't quit (in client) on connection failure) posted (#1) for review on master by Jeff Darcy (jdarcy)
I was wondering why this hadn't updated from POST to MODIFIED automatically, but then I saw that it shouldn't have gone to POST in the first place because this is the 3.10 version of the bug for which no patch has been backported yet.
REVIEW: https://review.gluster.org/16886 (glusterfsd: don't quit (in client) on connection failure) posted (#1) for review on release-3.10 by Jeff Darcy (jdarcy)
COMMIT: https://review.gluster.org/16886 committed in release-3.10 by Shyamsundar Ranganathan (srangana) ------ commit 2579daf23d6039d2b001d6e2392a952b39317af4 Author: Jeff Darcy <jdarcy> Date: Tue Mar 7 11:53:04 2017 -0500 glusterfsd: don't quit (in client) on connection failure Backport of: > eb038c19e2c799e35e72eeb500dfb81efc5567e2 > BUG: 1430042 > Reviewed-on: https://review.gluster.org/16866 Change-Id: I32be91e9db361a45454d6340a4c4ac2d0d7efffc BUG: 1422781 Signed-off-by: Jeff Darcy <jdarcy> Reviewed-on: https://review.gluster.org/16886 Smoke: Gluster Build System <jenkins.org> NetBSD-regression: NetBSD Build System <jenkins.org> CentOS-regression: Gluster Build System <jenkins.org> Reviewed-by: Shyamsundar Ranganathan <srangana>
This bug is getting closed because a release has been made available that should address the reported issue. In case the problem is still not fixed with glusterfs-3.10.1, please open a new bug report. glusterfs-3.10.1 has been announced on the Gluster mailinglists [1], packages for several distributions should become available in the near future. Keep an eye on the Gluster Users mailinglist [2] and the update infrastructure for your distribution. [1] http://lists.gluster.org/pipermail/gluster-users/2017-April/030494.html [2] https://www.gluster.org/pipermail/gluster-users/