Soumya Koduri
2016-Mar-08 14:42 UTC
[Gluster-users] NFS Client issues with Gluster Server 3.6.9
The log file didn't have any errors logged. Please check the NFS client logs in '/var/log/messages' or using dmesg and brick logs as well. Probably strace or packet trace could help too. You could use the below command to capture the pkt trace while running the I/Os on the node where gluster-nfs server is running : $ tcpdump -i any -s 0 -w /var/tmp/nfs.pcap tcp and not port 22 Check the file later to see what operation had failed (using filters: nfs, glusterfs). Thanks, Soumya On 03/07/2016 09:41 PM, Mark Selby wrote:> Here are the logs that you requested > > Please let me know if I can send you anything else. > > I really appreciate you taking a look at this - thanks! > > > root at dc1strg001x /root 547# gluster vol info backups > > Volume Name: backups > Type: Replicate > Volume ID: 71a26ea6-632d-4a1d-8610-e782ce2a5100 > Status: Started > Number of Bricks: 1 x 2 = 2 > Transport-type: tcp > Bricks: > Brick1: dc1strg001x:/zfspool/glusterfs/backups/data > Brick2: dc1strg002x:/zfspool/glusterfs/backups/data > Options Reconfigured: > nfs.disable: off > > > root at dc1strg001x /var/log/glusterfs 551# cat nfs.log > [2016-03-07 16:03:14.257919] I [MSGID: 100030] [glusterfsd.c:2318:main] > 0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version 3.7.6 > (args: /usr/sbin/glusterfs -s localhost --volfile-id gluster/nfs -p > /var/lib/glusterd/nfs/run/nfs.pid -l /var/log/glusterfs/nfs.log -S > /var/run/gluster/ad38be3bd1baece29e1b672e6659ae60.socket) > [2016-03-07 16:03:14.267862] I [MSGID: 101190] > [event-epoll.c:632:event_dispatch_epoll_worker] 0-epoll: Started thread > with index 1 > [2016-03-07 16:03:14.273283] I > [rpcsvc.c:2215:rpcsvc_set_outstanding_rpc_limit] 0-rpc-service: > Configured rpc.outstanding-rpc-limit with value 16 > [2016-03-07 16:03:14.284154] W [MSGID: 112153] > [mount3.c:3929:mnt3svc_init] 0-nfs-mount: Exports auth has been disabled! > [2016-03-07 16:03:14.306163] I [rpc-drc.c:694:rpcsvc_drc_init] > 0-rpc-service: DRC is turned OFF > [2016-03-07 16:03:14.306216] I [MSGID: 112110] [nfs.c:1494:init] 0-nfs: > NFS service started > [2016-03-07 16:03:14.312901] I [MSGID: 101190] > [event-epoll.c:632:event_dispatch_epoll_worker] 0-epoll: Started thread > with index 2 > [2016-03-07 16:03:14.314078] W [graph.c:357:_log_if_unknown_option] > 0-nfs-server: option 'rpc-auth.auth-glusterfs' is not recognized > [2016-03-07 16:03:14.314137] W [graph.c:357:_log_if_unknown_option] > 0-nfs-server: option 'rpc-auth-allow-insecure' is not recognized > [2016-03-07 16:03:14.314185] W [graph.c:357:_log_if_unknown_option] > 0-nfs-server: option 'transport-type' is not recognized > [2016-03-07 16:03:14.314270] I [MSGID: 114020] [client.c:2118:notify] > 0-backups-client-0: parent translators are ready, attempting connect on > transport > [2016-03-07 16:03:14.315341] I [MSGID: 114020] [client.c:2118:notify] > 0-backups-client-1: parent translators are ready, attempting connect on > transport > [2016-03-07 16:03:14.315923] I [rpc-clnt.c:1847:rpc_clnt_reconfig] > 0-backups-client-0: changing port to 49152 (from 0) > Final graph: > +------------------------------------------------------------------------------+ > > 1: volume backups-client-0 > 2: type protocol/client > 3: option ping-timeout 42 > 4: option remote-host dc1strg001x > 5: option remote-subvolume /zfspool/glusterfs/backups/data > 6: option transport-type socket > 7: option username 42fa7a62-1420-4169-ad00-53c3481dbe5b > 8: option password b71b3c88-51e0-464c-8b09-14b661fdb4d3 > 9: option send-gids true > 10: end-volume > 11: > 12: volume backups-client-1 > 13: type protocol/client > 14: option ping-timeout 42 > 15: option remote-host dc1strg002x > [2016-03-07 16:03:14.317412] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-backups-client-0: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > 16: option remote-subvolume /zfspool/glusterfs/backups/data > 17: option transport-type socket > 18: option username 42fa7a62-1420-4169-ad00-53c3481dbe5b > 19: option password b71b3c88-51e0-464c-8b09-14b661fdb4d3 > 20: option send-gids true > 21: end-volume > 22: > 23: volume backups-replicate-0 > 24: type cluster/replicate > 25: subvolumes backups-client-0 backups-client-1 > 26: end-volume > 27: > 28: volume backups-dht > 29: type cluster/distribute > 30: subvolumes backups-replicate-0 > 31: end-volume > 32: > 33: volume backups-write-behind > 34: type performance/write-behind > 35: subvolumes backups-dht > 36: end-volume > 37: > 38: volume backups > 39: type debug/io-stats > 40: option latency-measurement off > 41: option count-fop-hits off > 42: subvolumes backups-write-behind > 43: end-volume > 44: > 45: volume nfs-server > 46: type nfs/server > 47: option rpc-auth.auth-glusterfs on > 48: option rpc-auth.auth-unix on > 49: option rpc-auth.auth-null on > 50: option rpc-auth.ports.insecure on > 51: option rpc-auth-allow-insecure on > 52: option transport-type socket > 53: option transport.socket.listen-port 2049 > 54: option nfs.dynamic-volumes on > 55: option nfs.nlm on > 56: option nfs.drc off > 57: option rpc-auth.addr.backups.allow * > 58: option nfs3.backups.volume-id > 71a26ea6-632d-4a1d-8610-e782ce2a5100 > 59: option nfs.backups.disable off > 60: option nfs.logs.disable off > 61: option nfs.users.disable off > 62: subvolumes backups > 63: end-volume > 64: > +------------------------------------------------------------------------------+ > > [2016-03-07 16:03:14.318157] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-backups-client-0: > Connected to backups-client-0, attached to remote volume > '/zfspool/glusterfs/backups/data'. > [2016-03-07 16:03:14.318276] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-backups-client-0: > Server and Client lk-version numbers are not same, reopening the fds > [2016-03-07 16:03:14.318400] I [MSGID: 108005] > [afr-common.c:3841:afr_notify] 0-backups-replicate-0: Subvolume > 'backups-client-0' came back up; going online. > [2016-03-07 16:03:14.318470] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-backups-client-0: > Server lk version = 1 > [2016-03-07 16:03:14.496642] I [rpc-clnt.c:1847:rpc_clnt_reconfig] > 0-backups-client-1: changing port to 49152 (from 0) > [2016-03-07 16:03:14.498394] I [MSGID: 114057] > [client-handshake.c:1437:select_server_supported_programs] > 0-backups-client-1: Using Program GlusterFS 3.3, Num (1298437), Version > (330) > [2016-03-07 16:03:14.505580] I [MSGID: 114046] > [client-handshake.c:1213:client_setvolume_cbk] 0-backups-client-1: > Connected to backups-client-1, attached to remote volume > '/zfspool/glusterfs/backups/data'. > [2016-03-07 16:03:14.505627] I [MSGID: 114047] > [client-handshake.c:1224:client_setvolume_cbk] 0-backups-client-1: > Server and Client lk-version numbers are not same, reopening the fds > [2016-03-07 16:03:14.506210] I [MSGID: 114035] > [client-handshake.c:193:client_set_lk_version_cbk] 0-backups-client-1: > Server lk version = 1 > [2016-03-07 16:03:14.507836] I [MSGID: 108031] > [afr-common.c:1782:afr_local_discovery_cbk] 0-backups-replicate-0: > selecting local read_child backups-client-0 > > > > > On 3/6/16 9:13 PM, Jiffin Tony Thottan wrote: >> >> >> On 05/03/16 07:12, Mark Selby wrote: >>> I am trying to use GlusterFS as a general purpose NFS file server. I >>> have tried using the FUSE client but the performance fall off vs NFS >>> is quite large >>> >>> Both the client and the server are Ubuntu 14.04. >>> >>> I am using Gluster 3.6.9 because of the FUSE performance issues that >>> have been reported with 3.7.8 (see >>> https://bugzilla.redhat.com/show_bug.cgi?id=1309462) >>> >>> I am having serious issues with a generic NFS client as shown by the >>> issues below. Basically most FOPs are giving me a Remote I/O error. >>> >>> I would not think I was 1st person to see these issues - but my >>> Google Fu is not working. >>> >>> Any and all help would be much appreciated >>> >>> BTW - These operation against a plain Linux NFS server work fine. >>> >>> >>> root at dc1strg001x /var/log 448# gluster volume status >>> Status of volume: backups >>> Gluster process Port Online Pid >>> ------------------------------------------------------------------------------ >>> >>> Brick dc1strg001x:/zfspool/glusterfs/backups/data 49152 Y 6462 >>> Brick dc1strg002x:/zfspool/glusterfs/backups/data 49152 Y 6382 >>> NFS Server on localhost 2049 Y 6619 >>> Self-heal Daemon on localhost N/A Y 6626 >>> NFS Server on dc1strg002x 2049 Y 6502 >>> Self-heal Daemon on dc1strg002x N/A Y 6509 >>> >>> >>> root at vc1test001 /root 735# mount -o vers=3 -t nfs >>> dc1strg001x:/backups /mnt/backups_nfs >>> >>> root at vc1test001 /mnt/backups_nfs 737# dd if=/dev/zero of=testfile >>> bs=16k count=16384 >>> 16384+0 records in >>> 16384+0 records out >>> 268435456 bytes (268 MB) copied, 2.46237 s, 109 MB/s >>> >>> root at vc1test001 /mnt/backups_nfs 738# rm testfile >>> >>> root at vc1test001 /mnt/backups_nfs 739# dd if=/dev/zero of=testfile >>> bs=16k count=16384 >>> dd: failed to open ~testfile~: Remote I/O error >>> >>> root at vc1test001 /var/tmp 743# rsync -av testfile /mnt/backups_nfs/ >>> sending incremental file list >>> testfile >>> rsync: mkstemp "/mnt/backups_nfs/.testfile.bzg47C" failed: Remote I/O >>> error (121) >>> >>> sent 1,074,004,056 bytes received 121 bytes 165,231,411.85 bytes/sec >>> total size is 1,073,741,824 speedup is 1.00 >>> rsync error: some files/attrs were not transferred (see previous >>> errors) (code 23) at main.c(1183) [sender=3.1.0] >>> >> >> Can you please provide the volume configuration(gluster vol info ) >> and log file for nfs server which u mounted (/var/log/glusterfs) >> >> -- >> Jiffin >>> _______________________________________________ >>> Gluster-users mailing list >>> Gluster-users at gluster.org >>> http://www.gluster.org/mailman/listinfo/gluster-users >> > > _______________________________________________ > Gluster-users mailing list > Gluster-users at gluster.org > http://www.gluster.org/mailman/listinfo/gluster-users
Mark Selby
2016-Mar-09 22:46 UTC
[Gluster-users] NFS Client issues with Gluster Server 3.6.9
Like you I have checked all the logs that I have access to and I can not figure out what is going on. I have done a whole bunch of tcpdumps and I can not seem to make much sense of them The only thing that really sticks out are a lot of 'fh Unknown' messages I have pasted the dumps below - If you have minute and can take a quick look that would be greatly appreciated I have mounted nfs a directory and all I am doing is -- touch goo; rm goo; echo goo>goo This results in a Remote I/O error when I try and recreate the goo file. ########### # tcpdump # ########### root at dc1test001 /root 144# tcpdump -i any -s 0 not host dc1test002 and tcp and port 2049 tcpdump: verbose output suppressed, use -v or -vv for full protocol decode listening on any, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes 22:37:33.772016 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 2973245987:2973246131, ack 111853069, win 1282, options [nop,nop,TS val 4004375 ecr 17107903], length 144: NFS request xid 416076561 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.772016 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 0:144, ack 1, win 1282, options [nop,nop,TS val 4004375 ecr 17107903], length 144: NFS request xid 416076561 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.772016 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 0:144, ack 1, win 1282, options [nop,nop,TS val 4004375 ecr 17107903], length 144: NFS request xid 416076561 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.773061 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 1:265, ack 144, win 1223, options [nop,nop,TS val 17108904 ecr 4004375], length 264: NFS reply xid 416076561 reply ok 260 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC 22:37:33.773074 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 1:265, ack 144, win 1223, options [nop,nop,TS val 17108904 ecr 4004375], length 264: NFS reply xid 416076561 reply ok 260 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC 22:37:33.773077 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 1:265, ack 144, win 1223, options [nop,nop,TS val 17108904 ecr 4004375], length 264: NFS reply xid 416076561 reply ok 260 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC 22:37:33.773361 IP dc1test003.962 > dc1test001.nfs: Flags [.], ack 265, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 0 22:37:33.773361 IP dc1test003.962 > dc1test001.nfs: Flags [.], ack 265, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 0 22:37:33.773361 IP dc1test003.962 > dc1test001.nfs: Flags [.], ack 265, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 0 22:37:33.773394 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 144:284, ack 265, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 140: NFS request xid 432853777 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC NFS_ACCESS_READ|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_EXECUTE 22:37:33.773394 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 144:284, ack 265, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 140: NFS request xid 432853777 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC NFS_ACCESS_READ|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_EXECUTE 22:37:33.773394 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 144:284, ack 265, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 140: NFS request xid 432853777 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC NFS_ACCESS_READ|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_EXECUTE 22:37:33.773871 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 265:305, ack 284, win 1232, options [nop,nop,TS val 17108904 ecr 4004375], length 40: NFS reply xid 432853777 reply ok 36 access c 002d 22:37:33.773885 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 265:305, ack 284, win 1232, options [nop,nop,TS val 17108904 ecr 4004375], length 40: NFS reply xid 432853777 reply ok 36 access c 002d 22:37:33.773887 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 265:305, ack 284, win 1232, options [nop,nop,TS val 17108904 ecr 4004375], length 40: NFS reply xid 432853777 reply ok 36 access c 002d 22:37:33.774228 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 284:448, ack 305, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 164: NFS request xid 449630993 setattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC 22:37:33.774228 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 284:448, ack 305, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 164: NFS request xid 449630993 setattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC 22:37:33.774228 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 284:448, ack 305, win 1296, options [nop,nop,TS val 4004375 ecr 17108904], length 164: NFS request xid 449630993 setattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC 22:37:33.774952 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 305:453, ack 448, win 1240, options [nop,nop,TS val 17108905 ecr 4004375], length 148: NFS reply xid 449630993 reply ok 144 setattr 22:37:33.774966 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 305:453, ack 448, win 1240, options [nop,nop,TS val 17108905 ecr 4004375], length 148: NFS reply xid 449630993 reply ok 144 setattr 22:37:33.774969 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 305:453, ack 448, win 1240, options [nop,nop,TS val 17108905 ecr 4004375], length 148: NFS reply xid 449630993 reply ok 144 setattr 22:37:33.776824 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 448:592, ack 453, win 1309, options [nop,nop,TS val 4004376 ecr 17108905], length 144: NFS request xid 466408209 remove fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.776824 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 448:592, ack 453, win 1309, options [nop,nop,TS val 4004376 ecr 17108905], length 144: NFS request xid 466408209 remove fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.776824 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 448:592, ack 453, win 1309, options [nop,nop,TS val 4004376 ecr 17108905], length 144: NFS request xid 466408209 remove fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.777725 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 453:601, ack 592, win 1248, options [nop,nop,TS val 17108905 ecr 4004376], length 148: NFS reply xid 466408209 reply ok 144 remove 22:37:33.777739 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 453:601, ack 592, win 1248, options [nop,nop,TS val 17108905 ecr 4004376], length 148: NFS reply xid 466408209 reply ok 144 remove 22:37:33.777742 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 453:601, ack 592, win 1248, options [nop,nop,TS val 17108905 ecr 4004376], length 148: NFS reply xid 466408209 reply ok 144 remove 22:37:33.778260 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 592:732, ack 601, win 1322, options [nop,nop,TS val 4004376 ecr 17108905], length 140: NFS request xid 483185425 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 NFS_ACCESS_READ|NFS_ACCESS_LOOKUP|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_DELETE 22:37:33.778260 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 592:732, ack 601, win 1322, options [nop,nop,TS val 4004376 ecr 17108905], length 140: NFS request xid 483185425 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 NFS_ACCESS_READ|NFS_ACCESS_LOOKUP|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_DELETE 22:37:33.778260 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 592:732, ack 601, win 1322, options [nop,nop,TS val 4004376 ecr 17108905], length 140: NFS request xid 483185425 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 NFS_ACCESS_READ|NFS_ACCESS_LOOKUP|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_DELETE 22:37:33.778727 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 601:641, ack 732, win 1257, options [nop,nop,TS val 17108906 ecr 4004376], length 40: NFS reply xid 483185425 reply ok 36 access c 001f 22:37:33.778741 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 601:641, ack 732, win 1257, options [nop,nop,TS val 17108906 ecr 4004376], length 40: NFS reply xid 483185425 reply ok 36 access c 001f 22:37:33.778744 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 601:641, ack 732, win 1257, options [nop,nop,TS val 17108906 ecr 4004376], length 40: NFS reply xid 483185425 reply ok 36 access c 001f 22:37:33.778998 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 732:876, ack 641, win 1322, options [nop,nop,TS val 4004377 ecr 17108906], length 144: NFS request xid 499962641 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.778998 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 732:876, ack 641, win 1322, options [nop,nop,TS val 4004377 ecr 17108906], length 144: NFS request xid 499962641 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.778998 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 732:876, ack 641, win 1322, options [nop,nop,TS val 4004377 ecr 17108906], length 144: NFS request xid 499962641 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.779946 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 641:677, ack 876, win 1265, options [nop,nop,TS val 17108906 ecr 4004377], length 36: NFS reply xid 499962641 reply ok 32 lookup ERROR: No such file or directory 22:37:33.779960 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 641:677, ack 876, win 1265, options [nop,nop,TS val 17108906 ecr 4004377], length 36: NFS reply xid 499962641 reply ok 32 lookup ERROR: No such file or directory 22:37:33.779962 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 641:677, ack 876, win 1265, options [nop,nop,TS val 17108906 ecr 4004377], length 36: NFS reply xid 499962641 reply ok 32 lookup ERROR: No such file or directory 22:37:33.780210 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 876:1052, ack 677, win 1322, options [nop,nop,TS val 4004377 ecr 17108906], length 176: NFS request xid 516739857 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.780210 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 876:1052, ack 677, win 1322, options [nop,nop,TS val 4004377 ecr 17108906], length 176: NFS request xid 516739857 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.780210 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 876:1052, ack 677, win 1322, options [nop,nop,TS val 4004377 ecr 17108906], length 176: NFS request xid 516739857 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:37:33.781367 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 677:973, ack 1052, win 1274, options [nop,nop,TS val 17108906 ecr 4004377], length 296: NFS reply xid 516739857 reply ok 292 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD40F22239C3334CCD80082C24 22:37:33.781377 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 677:973, ack 1052, win 1274, options [nop,nop,TS val 17108906 ecr 4004377], length 296: NFS reply xid 516739857 reply ok 292 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD40F22239C3334CCD80082C24 22:37:33.781380 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 677:973, ack 1052, win 1274, options [nop,nop,TS val 17108906 ecr 4004377], length 296: NFS reply xid 516739857 reply ok 292 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD40F22239C3334CCD80082C24 22:37:33.781640 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 1052:1192, ack 973, win 1335, options [nop,nop,TS val 4004377 ecr 17108906], length 140: NFS request xid 533517073 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:37:33.781640 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 1052:1192, ack 973, win 1335, options [nop,nop,TS val 4004377 ecr 17108906], length 140: NFS request xid 533517073 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:37:33.781640 IP dc1test003.962 > dc1test001.nfs: Flags [P.], seq 1052:1192, ack 973, win 1335, options [nop,nop,TS val 4004377 ecr 17108906], length 140: NFS request xid 533517073 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:37:33.782262 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 973:1113, ack 1192, win 1282, options [nop,nop,TS val 17108907 ecr 4004377], length 140: NFS reply xid 533517073 reply ok 136 getattr ERROR: Unspecified error on server 22:37:33.782271 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 973:1113, ack 1192, win 1282, options [nop,nop,TS val 17108907 ecr 4004377], length 140: NFS reply xid 533517073 reply ok 136 getattr ERROR: Unspecified error on server 22:37:33.782273 IP dc1test001.nfs > dc1test003.962: Flags [P.], seq 973:1113, ack 1192, win 1282, options [nop,nop,TS val 17108907 ecr 4004377], length 140: NFS reply xid 533517073 reply ok 136 getattr ERROR: Unspecified error on server 22:37:33.822533 IP dc1test003.962 > dc1test001.nfs: Flags [.], ack 1113, win 1349, options [nop,nop,TS val 4004388 ecr 17108907], length 0 22:37:33.822533 IP dc1test003.962 > dc1test001.nfs: Flags [.], ack 1113, win 1349, options [nop,nop,TS val 4004388 ecr 17108907], length 0 22:37:33.822533 IP dc1test003.962 > dc1test001.nfs: Flags [.], ack 1113, win 1349, options [nop,nop,TS val 4004388 ecr 17108907], length 0 ################### # tcpdump verbose # ################### root at dc1test001 /root 142# tcpdump -i any -v -s 0 not host dc1test002 and tcp and port 2049 tcpdump: listening on any, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes 22:36:39.715407 IP (tos 0x0, ttl 63, id 4196, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x11b8 (correct), seq 2973244251:2973244391, ack 111851325, win 1176, options [nop,nop,TS val 3990861 ecr 17092903], length 140: NFS request xid 214749969 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 NFS_ACCESS_READ|NFS_ACCESS_LOOKUP|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_DELETE 22:36:39.715407 IP (tos 0x0, ttl 63, id 4196, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x11b8 (correct), seq 0:140, ack 1, win 1176, options [nop,nop,TS val 3990861 ecr 17092903], length 140: NFS request xid 214749969 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 NFS_ACCESS_READ|NFS_ACCESS_LOOKUP|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_DELETE 22:36:39.715407 IP (tos 0x0, ttl 63, id 4196, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x11b8 (correct), seq 0:140, ack 1, win 1176, options [nop,nop,TS val 3990861 ecr 17092903], length 140: NFS request xid 214749969 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 NFS_ACCESS_READ|NFS_ACCESS_LOOKUP|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_DELETE 22:36:39.715972 IP (tos 0x0, ttl 64, id 37645, offset 0, flags [DF], proto TCP (6), length 92) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5e (incorrect -> 0x8cc1), seq 1:41, ack 140, win 1123, options [nop,nop,TS val 17095390 ecr 3990861], length 40: NFS reply xid 214749969 reply ok 36 access attr: c 001f 22:36:39.715985 IP (tos 0x0, ttl 64, id 37645, offset 0, flags [DF], proto TCP (6), length 92) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5e (incorrect -> 0x8cc1), seq 1:41, ack 140, win 1123, options [nop,nop,TS val 17095390 ecr 3990861], length 40: NFS reply xid 214749969 reply ok 36 access attr: c 001f 22:36:39.715988 IP (tos 0x0, ttl 64, id 37645, offset 0, flags [DF], proto TCP (6), length 92) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5e (incorrect -> 0x8cc1), seq 1:41, ack 140, win 1123, options [nop,nop,TS val 17095390 ecr 3990861], length 40: NFS reply xid 214749969 reply ok 36 access attr: c 001f 22:36:39.716246 IP (tos 0x0, ttl 63, id 4197, offset 0, flags [DF], proto TCP (6), length 52) dc1test003.962 > dc1test001.nfs: Flags [.], cksum 0xecb6 (correct), ack 41, win 1176, options [nop,nop,TS val 3990861 ecr 17095390], length 0 22:36:39.716246 IP (tos 0x0, ttl 63, id 4197, offset 0, flags [DF], proto TCP (6), length 52) dc1test003.962 > dc1test001.nfs: Flags [.], cksum 0xecb6 (correct), ack 41, win 1176, options [nop,nop,TS val 3990861 ecr 17095390], length 0 22:36:39.716246 IP (tos 0x0, ttl 63, id 4197, offset 0, flags [DF], proto TCP (6), length 52) dc1test003.962 > dc1test001.nfs: Flags [.], cksum 0xecb6 (correct), ack 41, win 1176, options [nop,nop,TS val 3990861 ecr 17095390], length 0 22:36:39.716276 IP (tos 0x0, ttl 63, id 4198, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2ff2 (correct), seq 140:284, ack 41, win 1176, options [nop,nop,TS val 3990861 ecr 17095390], length 144: NFS request xid 231527185 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.716276 IP (tos 0x0, ttl 63, id 4198, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2ff2 (correct), seq 140:284, ack 41, win 1176, options [nop,nop,TS val 3990861 ecr 17095390], length 144: NFS request xid 231527185 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.716276 IP (tos 0x0, ttl 63, id 4198, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2ff2 (correct), seq 140:284, ack 41, win 1176, options [nop,nop,TS val 3990861 ecr 17095390], length 144: NFS request xid 231527185 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.717087 IP (tos 0x0, ttl 64, id 37646, offset 0, flags [DF], proto TCP (6), length 316) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2e3e (incorrect -> 0x2201), seq 41:305, ack 284, win 1131, options [nop,nop,TS val 17095390 ecr 3990861], length 264: NFS reply xid 231527185 reply ok 260 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 REG 644 ids 0/0 sz 0 22:36:39.717101 IP (tos 0x0, ttl 64, id 37646, offset 0, flags [DF], proto TCP (6), length 316) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2e3e (incorrect -> 0x2201), seq 41:305, ack 284, win 1131, options [nop,nop,TS val 17095390 ecr 3990861], length 264: NFS reply xid 231527185 reply ok 260 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 REG 644 ids 0/0 sz 0 22:36:39.717103 IP (tos 0x0, ttl 64, id 37646, offset 0, flags [DF], proto TCP (6), length 316) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2e3e (incorrect -> 0x2201), seq 41:305, ack 284, win 1131, options [nop,nop,TS val 17095390 ecr 3990861], length 264: NFS reply xid 231527185 reply ok 260 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 REG 644 ids 0/0 sz 0 22:36:39.717420 IP (tos 0x0, ttl 63, id 4199, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x7a3f (correct), seq 284:424, ack 305, win 1190, options [nop,nop,TS val 3990861 ecr 17095390], length 140: NFS request xid 248304401 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 NFS_ACCESS_READ|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_EXECUTE 22:36:39.717420 IP (tos 0x0, ttl 63, id 4199, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x7a3f (correct), seq 284:424, ack 305, win 1190, options [nop,nop,TS val 3990861 ecr 17095390], length 140: NFS request xid 248304401 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 NFS_ACCESS_READ|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_EXECUTE 22:36:39.717420 IP (tos 0x0, ttl 63, id 4199, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x7a3f (correct), seq 284:424, ack 305, win 1190, options [nop,nop,TS val 3990861 ecr 17095390], length 140: NFS request xid 248304401 access fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 NFS_ACCESS_READ|NFS_ACCESS_MODIFY|NFS_ACCESS_EXTEND|NFS_ACCESS_EXECUTE 22:36:39.717912 IP (tos 0x0, ttl 64, id 37647, offset 0, flags [DF], proto TCP (6), length 92) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5e (incorrect -> 0x8856), seq 305:345, ack 424, win 1140, options [nop,nop,TS val 17095390 ecr 3990861], length 40: NFS reply xid 248304401 reply ok 36 access attr: c 002d 22:36:39.717925 IP (tos 0x0, ttl 64, id 37647, offset 0, flags [DF], proto TCP (6), length 92) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5e (incorrect -> 0x8856), seq 305:345, ack 424, win 1140, options [nop,nop,TS val 17095390 ecr 3990861], length 40: NFS reply xid 248304401 reply ok 36 access attr: c 002d 22:36:39.717928 IP (tos 0x0, ttl 64, id 37647, offset 0, flags [DF], proto TCP (6), length 92) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5e (incorrect -> 0x8856), seq 305:345, ack 424, win 1140, options [nop,nop,TS val 17095390 ecr 3990861], length 40: NFS reply xid 248304401 reply ok 36 access attr: c 002d 22:36:39.718265 IP (tos 0x0, ttl 63, id 4200, offset 0, flags [DF], proto TCP (6), length 216) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x7888 (correct), seq 424:588, ack 345, win 1190, options [nop,nop,TS val 3990861 ecr 17095390], length 164: NFS request xid 265081617 setattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 22:36:39.718265 IP (tos 0x0, ttl 63, id 4200, offset 0, flags [DF], proto TCP (6), length 216) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x7888 (correct), seq 424:588, ack 345, win 1190, options [nop,nop,TS val 3990861 ecr 17095390], length 164: NFS request xid 265081617 setattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 22:36:39.718265 IP (tos 0x0, ttl 63, id 4200, offset 0, flags [DF], proto TCP (6), length 216) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x7888 (correct), seq 424:588, ack 345, win 1190, options [nop,nop,TS val 3990861 ecr 17095390], length 164: NFS request xid 265081617 setattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CDC8D91E5F0F934C2AA60D09A0 22:36:39.719007 IP (tos 0x0, ttl 64, id 37648, offset 0, flags [DF], proto TCP (6), length 200) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dca (incorrect -> 0x1776), seq 345:493, ack 588, win 1148, options [nop,nop,TS val 17095391 ecr 3990861], length 148: NFS reply xid 265081617 reply ok 144 setattr POST: REG 644 ids 0/0 sz 0 22:36:39.719020 IP (tos 0x0, ttl 64, id 37648, offset 0, flags [DF], proto TCP (6), length 200) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dca (incorrect -> 0x1776), seq 345:493, ack 588, win 1148, options [nop,nop,TS val 17095391 ecr 3990861], length 148: NFS reply xid 265081617 reply ok 144 setattr POST: REG 644 ids 0/0 sz 0 22:36:39.719023 IP (tos 0x0, ttl 64, id 37648, offset 0, flags [DF], proto TCP (6), length 200) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dca (incorrect -> 0x1776), seq 345:493, ack 588, win 1148, options [nop,nop,TS val 17095391 ecr 3990861], length 148: NFS reply xid 265081617 reply ok 144 setattr POST: REG 644 ids 0/0 sz 0 22:36:39.720930 IP (tos 0x0, ttl 63, id 4201, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2948 (correct), seq 588:732, ack 493, win 1203, options [nop,nop,TS val 3990862 ecr 17095391], length 144: NFS request xid 281858833 remove fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.720930 IP (tos 0x0, ttl 63, id 4201, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2948 (correct), seq 588:732, ack 493, win 1203, options [nop,nop,TS val 3990862 ecr 17095391], length 144: NFS request xid 281858833 remove fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.720930 IP (tos 0x0, ttl 63, id 4201, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2948 (correct), seq 588:732, ack 493, win 1203, options [nop,nop,TS val 3990862 ecr 17095391], length 144: NFS request xid 281858833 remove fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.721826 IP (tos 0x0, ttl 64, id 37649, offset 0, flags [DF], proto TCP (6), length 200) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dca (incorrect -> 0x4d14), seq 493:641, ack 732, win 1156, options [nop,nop,TS val 17095391 ecr 3990862], length 148: NFS reply xid 281858833 reply ok 144 remove POST: DIR 755 ids 0/0 sz 4 22:36:39.721841 IP (tos 0x0, ttl 64, id 37649, offset 0, flags [DF], proto TCP (6), length 200) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dca (incorrect -> 0x4d14), seq 493:641, ack 732, win 1156, options [nop,nop,TS val 17095391 ecr 3990862], length 148: NFS reply xid 281858833 reply ok 144 remove POST: DIR 755 ids 0/0 sz 4 22:36:39.721852 IP (tos 0x0, ttl 64, id 37649, offset 0, flags [DF], proto TCP (6), length 200) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dca (incorrect -> 0x4d14), seq 493:641, ack 732, win 1156, options [nop,nop,TS val 17095391 ecr 3990862], length 148: NFS reply xid 281858833 reply ok 144 remove POST: DIR 755 ids 0/0 sz 4 22:36:39.722389 IP (tos 0x0, ttl 63, id 4202, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2720 (correct), seq 732:876, ack 641, win 1216, options [nop,nop,TS val 3990862 ecr 17095391], length 144: NFS request xid 298636049 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.722389 IP (tos 0x0, ttl 63, id 4202, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2720 (correct), seq 732:876, ack 641, win 1216, options [nop,nop,TS val 3990862 ecr 17095391], length 144: NFS request xid 298636049 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.722389 IP (tos 0x0, ttl 63, id 4202, offset 0, flags [DF], proto TCP (6), length 196) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2720 (correct), seq 732:876, ack 641, win 1216, options [nop,nop,TS val 3990862 ecr 17095391], length 144: NFS request xid 298636049 lookup fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.723426 IP (tos 0x0, ttl 64, id 37650, offset 0, flags [DF], proto TCP (6), length 88) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5a (incorrect -> 0x8259), seq 641:677, ack 876, win 1165, options [nop,nop,TS val 17095392 ecr 3990862], length 36: NFS reply xid 298636049 reply ok 32 lookup ERROR: No such file or directory 22:36:39.723440 IP (tos 0x0, ttl 64, id 37650, offset 0, flags [DF], proto TCP (6), length 88) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5a (incorrect -> 0x8259), seq 641:677, ack 876, win 1165, options [nop,nop,TS val 17095392 ecr 3990862], length 36: NFS reply xid 298636049 reply ok 32 lookup ERROR: No such file or directory 22:36:39.723444 IP (tos 0x0, ttl 64, id 37650, offset 0, flags [DF], proto TCP (6), length 88) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2d5a (incorrect -> 0x8259), seq 641:677, ack 876, win 1165, options [nop,nop,TS val 17095392 ecr 3990862], length 36: NFS reply xid 298636049 reply ok 32 lookup ERROR: No such file or directory 22:36:39.723698 IP (tos 0x0, ttl 63, id 4203, offset 0, flags [DF], proto TCP (6), length 228) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2380 (correct), seq 876:1052, ack 677, win 1216, options [nop,nop,TS val 3990863 ecr 17095392], length 176: NFS request xid 315413265 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.723698 IP (tos 0x0, ttl 63, id 4203, offset 0, flags [DF], proto TCP (6), length 228) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2380 (correct), seq 876:1052, ack 677, win 1216, options [nop,nop,TS val 3990863 ecr 17095392], length 176: NFS request xid 315413265 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.723698 IP (tos 0x0, ttl 63, id 4203, offset 0, flags [DF], proto TCP (6), length 228) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0x2380 (correct), seq 876:1052, ack 677, win 1216, options [nop,nop,TS val 3990863 ecr 17095392], length 176: NFS request xid 315413265 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 "goo" 22:36:39.724979 IP (tos 0x0, ttl 64, id 37651, offset 0, flags [DF], proto TCP (6), length 348) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2e5e (incorrect -> 0x1b13), seq 677:973, ack 1052, win 1173, options [nop,nop,TS val 17095392 ecr 3990863], length 296: NFS reply xid 315413265 reply ok 292 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC REG 644 ids 0/0 sz 0 22:36:39.724990 IP (tos 0x0, ttl 64, id 37651, offset 0, flags [DF], proto TCP (6), length 348) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2e5e (incorrect -> 0x1b13), seq 677:973, ack 1052, win 1173, options [nop,nop,TS val 17095392 ecr 3990863], length 296: NFS reply xid 315413265 reply ok 292 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC REG 644 ids 0/0 sz 0 22:36:39.725001 IP (tos 0x0, ttl 64, id 37651, offset 0, flags [DF], proto TCP (6), length 348) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2e5e (incorrect -> 0x1b13), seq 677:973, ack 1052, win 1173, options [nop,nop,TS val 17095392 ecr 3990863], length 296: NFS reply xid 315413265 reply ok 292 create fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD21CF2E61F45846EE933FFFEC REG 644 ids 0/0 sz 0 22:36:39.725256 IP (tos 0x0, ttl 63, id 4204, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0xf815 (correct), seq 1052:1192, ack 973, win 1229, options [nop,nop,TS val 3990863 ecr 17095392], length 140: NFS request xid 332190481 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:39.725256 IP (tos 0x0, ttl 63, id 4204, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0xf815 (correct), seq 1052:1192, ack 973, win 1229, options [nop,nop,TS val 3990863 ecr 17095392], length 140: NFS request xid 332190481 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:39.725256 IP (tos 0x0, ttl 63, id 4204, offset 0, flags [DF], proto TCP (6), length 192) dc1test003.962 > dc1test001.nfs: Flags [P.], cksum 0xf815 (correct), seq 1052:1192, ack 973, win 1229, options [nop,nop,TS val 3990863 ecr 17095392], length 140: NFS request xid 332190481 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:39.725933 IP (tos 0x0, ttl 64, id 37652, offset 0, flags [DF], proto TCP (6), length 192) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dc2 (incorrect -> 0x76f2), seq 973:1113, ack 1192, win 1181, options [nop,nop,TS val 17095392 ecr 3990863], length 140: NFS reply xid 332190481 reply ok 136 getattr ERROR: Unspecified error on server 22:36:39.725941 IP (tos 0x0, ttl 64, id 37652, offset 0, flags [DF], proto TCP (6), length 192) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dc2 (incorrect -> 0x76f2), seq 973:1113, ack 1192, win 1181, options [nop,nop,TS val 17095392 ecr 3990863], length 140: NFS reply xid 332190481 reply ok 136 getattr ERROR: Unspecified error on server 22:36:39.725943 IP (tos 0x0, ttl 64, id 37652, offset 0, flags [DF], proto TCP (6), length 192) dc1test001.nfs > dc1test003.962: Flags [P.], cksum 0x2dc2 (incorrect -> 0x76f2), seq 973:1113, ack 1192, win 1181, options [nop,nop,TS val 17095392 ecr 3990863], length 140: NFS reply xid 332190481 reply ok 136 getattr ERROR: Unspecified error on server 22:36:39.762562 IP (tos 0x0, ttl 63, id 4205, offset 0, flags [DF], proto TCP (6), length 52) dc1test003.962 > dc1test001.nfs: Flags [.], cksum 0xe419 (correct), ack 1113, win 1243, options [nop,nop,TS val 3990873 ecr 17095392], length 0 22:36:39.762562 IP (tos 0x0, ttl 63, id 4205, offset 0, flags [DF], proto TCP (6), length 52) dc1test003.962 > dc1test001.nfs: Flags [.], cksum 0xe419 (correct), ack 1113, win 1243, options [nop,nop,TS val 3990873 ecr 17095392], length 0 22:36:39.762562 IP (tos 0x0, ttl 63, id 4205, offset 0, flags [DF], proto TCP (6), length 52) dc1test003.962 > dc1test001.nfs: Flags [.], cksum 0xe419 (correct), ack 1113, win 1243, options [nop,nop,TS val 3990873 ecr 17095392], length 0 22:36:40.851774 IP (tos 0x0, ttl 62, id 59690, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x6f55 (correct), seq 2245991931:2245992067, ack 2222620198, win 1359, options [nop,nop,TS val 2705398265 ecr 17090675], length 136: NFS request xid 3743003364 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:40.851774 IP (tos 0x0, ttl 62, id 59690, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x6f55 (correct), seq 0:136, ack 1, win 1359, options [nop,nop,TS val 2705398265 ecr 17090675], length 136: NFS request xid 3743003364 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:40.851774 IP (tos 0x0, ttl 62, id 59690, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x6f55 (correct), seq 0:136, ack 1, win 1359, options [nop,nop,TS val 2705398265 ecr 17090675], length 136: NFS request xid 3743003364 getattr fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:40.852294 IP (tos 0x0, ttl 64, id 11639, offset 0, flags [DF], proto TCP (6), length 168) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2eb1 (incorrect -> 0x0748), seq 1:117, ack 136, win 1452, options [nop,nop,TS val 17095674 ecr 2705398265], length 116: NFS reply xid 3743003364 reply ok 112 getattr DIR 755 ids 0/0 sz 5 22:36:40.852307 IP (tos 0x0, ttl 64, id 11639, offset 0, flags [DF], proto TCP (6), length 168) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2eb1 (incorrect -> 0x0748), seq 1:117, ack 136, win 1452, options [nop,nop,TS val 17095674 ecr 2705398265], length 116: NFS reply xid 3743003364 reply ok 112 getattr DIR 755 ids 0/0 sz 5 22:36:40.852310 IP (tos 0x0, ttl 64, id 11639, offset 0, flags [DF], proto TCP (6), length 168) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2eb1 (incorrect -> 0x0748), seq 1:117, ack 136, win 1452, options [nop,nop,TS val 17095674 ecr 2705398265], length 116: NFS reply xid 3743003364 reply ok 112 getattr DIR 755 ids 0/0 sz 5 22:36:40.852605 IP (tos 0x0, ttl 62, id 59691, offset 0, flags [DF], proto TCP (6), length 52) vc1util001.684 > dc1test001.nfs: Flags [.], cksum 0xf8f8 (correct), ack 117, win 1359, options [nop,nop,TS val 2705398266 ecr 17095674], length 0 22:36:40.852605 IP (tos 0x0, ttl 62, id 59691, offset 0, flags [DF], proto TCP (6), length 52) vc1util001.684 > dc1test001.nfs: Flags [.], cksum 0xf8f8 (correct), ack 117, win 1359, options [nop,nop,TS val 2705398266 ecr 17095674], length 0 22:36:40.852605 IP (tos 0x0, ttl 62, id 59691, offset 0, flags [DF], proto TCP (6), length 52) vc1util001.684 > dc1test001.nfs: Flags [.], cksum 0xf8f8 (correct), ack 117, win 1359, options [nop,nop,TS val 2705398266 ecr 17095674], length 0 22:36:40.853423 IP (tos 0x0, ttl 62, id 59692, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x5b8a (correct), seq 136:272, ack 117, win 1359, options [nop,nop,TS val 2705398266 ecr 17095674], length 136: NFS request xid 3759780580 fsstat fh Unknown/3A4F474CB9B0E7ADE4D1473EABE4B4597E909CDE000000000000000000000000 22:36:40.853423 IP (tos 0x0, ttl 62, id 59692, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x5b8a (correct), seq 136:272, ack 117, win 1359, options [nop,nop,TS val 2705398266 ecr 17095674], length 136: NFS request xid 3759780580 fsstat fh Unknown/3A4F474CB9B0E7ADE4D1473EABE4B4597E909CDE000000000000000000000000 22:36:40.853423 IP (tos 0x0, ttl 62, id 59692, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x5b8a (correct), seq 136:272, ack 117, win 1359, options [nop,nop,TS val 2705398266 ecr 17095674], length 136: NFS request xid 3759780580 fsstat fh Unknown/3A4F474CB9B0E7ADE4D1473EABE4B4597E909CDE000000000000000000000000 22:36:40.854641 IP (tos 0x0, ttl 64, id 11640, offset 0, flags [DF], proto TCP (6), length 224) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2ee9 (incorrect -> 0x2634), seq 117:289, ack 272, win 1452, options [nop,nop,TS val 17095675 ecr 2705398266], length 172: NFS reply xid 3759780580 reply ok 168 fsstat POST: DIR 755 ids 0/0 sz 9 tbytes 1930513743872 fbytes 1930513612800 abytes 1930513612800 tfiles 3770534746 ffiles 3770534593 afiles 3770534593 invar 0 22:36:40.854655 IP (tos 0x0, ttl 64, id 11640, offset 0, flags [DF], proto TCP (6), length 224) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2ee9 (incorrect -> 0x2634), seq 117:289, ack 272, win 1452, options [nop,nop,TS val 17095675 ecr 2705398266], length 172: NFS reply xid 3759780580 reply ok 168 fsstat POST: DIR 755 ids 0/0 sz 9 tbytes 1930513743872 fbytes 1930513612800 abytes 1930513612800 tfiles 3770534746 ffiles 3770534593 afiles 3770534593 invar 0 22:36:40.854658 IP (tos 0x0, ttl 64, id 11640, offset 0, flags [DF], proto TCP (6), length 224) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2ee9 (incorrect -> 0x2634), seq 117:289, ack 272, win 1452, options [nop,nop,TS val 17095675 ecr 2705398266], length 172: NFS reply xid 3759780580 reply ok 168 fsstat POST: DIR 755 ids 0/0 sz 9 tbytes 1930513743872 fbytes 1930513612800 abytes 1930513612800 tfiles 3770534746 ffiles 3770534593 afiles 3770534593 invar 0 22:36:40.855077 IP (tos 0x0, ttl 62, id 59693, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x5782 (correct), seq 272:408, ack 289, win 1368, options [nop,nop,TS val 2705398266 ecr 17095675], length 136: NFS request xid 3776557796 fsstat fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:40.855077 IP (tos 0x0, ttl 62, id 59693, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x5782 (correct), seq 272:408, ack 289, win 1368, options [nop,nop,TS val 2705398266 ecr 17095675], length 136: NFS request xid 3776557796 fsstat fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:40.855077 IP (tos 0x0, ttl 62, id 59693, offset 0, flags [DF], proto TCP (6), length 188) vc1util001.684 > dc1test001.nfs: Flags [P.], cksum 0x5782 (correct), seq 272:408, ack 289, win 1368, options [nop,nop,TS val 2705398266 ecr 17095675], length 136: NFS request xid 3776557796 fsstat fh Unknown/3A4F474C417593675D4940539F6AC7D9EF5B90CD000000000000000000000000 22:36:40.855956 IP (tos 0x0, ttl 64, id 11641, offset 0, flags [DF], proto TCP (6), length 224) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2ee9 (incorrect -> 0x87d5), seq 289:461, ack 408, win 1452, options [nop,nop,TS val 17095675 ecr 2705398266], length 172: NFS reply xid 3776557796 reply ok 168 fsstat POST: DIR 755 ids 0/0 sz 5 tbytes 1930513743872 fbytes 1930513612800 abytes 1930513612800 tfiles 3770534671 ffiles 3770534593 afiles 3770534593 invar 0 22:36:40.855970 IP (tos 0x0, ttl 64, id 11641, offset 0, flags [DF], proto TCP (6), length 224) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2ee9 (incorrect -> 0x87d5), seq 289:461, ack 408, win 1452, options [nop,nop,TS val 17095675 ecr 2705398266], length 172: NFS reply xid 3776557796 reply ok 168 fsstat POST: DIR 755 ids 0/0 sz 5 tbytes 1930513743872 fbytes 1930513612800 abytes 1930513612800 tfiles 3770534671 ffiles 3770534593 afiles 3770534593 invar 0 22:36:40.855973 IP (tos 0x0, ttl 64, id 11641, offset 0, flags [DF], proto TCP (6), length 224) dc1test001.nfs > vc1util001.684: Flags [P.], cksum 0x2ee9 (incorrect -> 0x87d5), seq 289:461, ack 408, win 1452, options [nop,nop,TS val 17095675 ecr 2705398266], length 172: NFS reply xid 3776557796 reply ok 168 fsstat POST: DIR 755 ids 0/0 sz 5 tbytes 1930513743872 fbytes 1930513612800 abytes 1930513612800 tfiles 3770534671 ffiles 3770534593 afiles 3770534593 invar 0 22:36:40.896009 IP (tos 0x0, ttl 62, id 59694, offset 0, flags [DF], proto TCP (6), length 52) vc1util001.684 > dc1test001.nfs: Flags [.], cksum 0xf673 (correct), ack 461, win 1376, options [nop,nop,TS val 2705398277 ecr 17095675], length 0 22:36:40.896009 IP (tos 0x0, ttl 62, id 59694, offset 0, flags [DF], proto TCP (6), length 52) vc1util001.684 > dc1test001.nfs: Flags [.], cksum 0xf673 (correct), ack 461, win 1376, options [nop,nop,TS val 2705398277 ecr 17095675], length 0 22:36:40.896009 IP (tos 0x0, ttl 62, id 59694, offset 0, flags [DF], proto TCP (6), length 52) vc1util001.684 > dc1test001.nfs: Flags [.], cksum 0xf673 (correct), ack 461, win 1376, options [nop,nop,TS val 2705398277 ecr 17095675], length 0 On 3/8/16 6:42 AM, Soumya Koduri wrote:> The log file didn't have any errors logged. Please check the NFS > client logs in '/var/log/messages' or using dmesg and brick logs as well. > > Probably strace or packet trace could help too. You could use the > below command to capture the pkt trace while running the I/Os on the > node where gluster-nfs server is running : > > $ tcpdump -i any -s 0 -w /var/tmp/nfs.pcap tcp and not port 22 > > Check the file later to see what operation had failed (using filters: > nfs, glusterfs). > > Thanks, > Soumya > > > On 03/07/2016 09:41 PM, Mark Selby wrote: >> Here are the logs that you requested >> >> Please let me know if I can send you anything else. >> >> I really appreciate you taking a look at this - thanks! >> >> >> root at dc1strg001x /root 547# gluster vol info backups >> >> Volume Name: backups >> Type: Replicate >> Volume ID: 71a26ea6-632d-4a1d-8610-e782ce2a5100 >> Status: Started >> Number of Bricks: 1 x 2 = 2 >> Transport-type: tcp >> Bricks: >> Brick1: dc1strg001x:/zfspool/glusterfs/backups/data >> Brick2: dc1strg002x:/zfspool/glusterfs/backups/data >> Options Reconfigured: >> nfs.disable: off >> >> >> root at dc1strg001x /var/log/glusterfs 551# cat nfs.log >> [2016-03-07 16:03:14.257919] I [MSGID: 100030] [glusterfsd.c:2318:main] >> 0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version 3.7.6 >> (args: /usr/sbin/glusterfs -s localhost --volfile-id gluster/nfs -p >> /var/lib/glusterd/nfs/run/nfs.pid -l /var/log/glusterfs/nfs.log -S >> /var/run/gluster/ad38be3bd1baece29e1b672e6659ae60.socket) >> [2016-03-07 16:03:14.267862] I [MSGID: 101190] >> [event-epoll.c:632:event_dispatch_epoll_worker] 0-epoll: Started thread >> with index 1 >> [2016-03-07 16:03:14.273283] I >> [rpcsvc.c:2215:rpcsvc_set_outstanding_rpc_limit] 0-rpc-service: >> Configured rpc.outstanding-rpc-limit with value 16 >> [2016-03-07 16:03:14.284154] W [MSGID: 112153] >> [mount3.c:3929:mnt3svc_init] 0-nfs-mount: Exports auth has been >> disabled! >> [2016-03-07 16:03:14.306163] I [rpc-drc.c:694:rpcsvc_drc_init] >> 0-rpc-service: DRC is turned OFF >> [2016-03-07 16:03:14.306216] I [MSGID: 112110] [nfs.c:1494:init] 0-nfs: >> NFS service started >> [2016-03-07 16:03:14.312901] I [MSGID: 101190] >> [event-epoll.c:632:event_dispatch_epoll_worker] 0-epoll: Started thread >> with index 2 >> [2016-03-07 16:03:14.314078] W [graph.c:357:_log_if_unknown_option] >> 0-nfs-server: option 'rpc-auth.auth-glusterfs' is not recognized >> [2016-03-07 16:03:14.314137] W [graph.c:357:_log_if_unknown_option] >> 0-nfs-server: option 'rpc-auth-allow-insecure' is not recognized >> [2016-03-07 16:03:14.314185] W [graph.c:357:_log_if_unknown_option] >> 0-nfs-server: option 'transport-type' is not recognized >> [2016-03-07 16:03:14.314270] I [MSGID: 114020] [client.c:2118:notify] >> 0-backups-client-0: parent translators are ready, attempting connect on >> transport >> [2016-03-07 16:03:14.315341] I [MSGID: 114020] [client.c:2118:notify] >> 0-backups-client-1: parent translators are ready, attempting connect on >> transport >> [2016-03-07 16:03:14.315923] I [rpc-clnt.c:1847:rpc_clnt_reconfig] >> 0-backups-client-0: changing port to 49152 (from 0) >> Final graph: >> +------------------------------------------------------------------------------+ >> >> >> 1: volume backups-client-0 >> 2: type protocol/client >> 3: option ping-timeout 42 >> 4: option remote-host dc1strg001x >> 5: option remote-subvolume /zfspool/glusterfs/backups/data >> 6: option transport-type socket >> 7: option username 42fa7a62-1420-4169-ad00-53c3481dbe5b >> 8: option password b71b3c88-51e0-464c-8b09-14b661fdb4d3 >> 9: option send-gids true >> 10: end-volume >> 11: >> 12: volume backups-client-1 >> 13: type protocol/client >> 14: option ping-timeout 42 >> 15: option remote-host dc1strg002x >> [2016-03-07 16:03:14.317412] I [MSGID: 114057] >> [client-handshake.c:1437:select_server_supported_programs] >> 0-backups-client-0: Using Program GlusterFS 3.3, Num (1298437), Version >> (330) >> 16: option remote-subvolume /zfspool/glusterfs/backups/data >> 17: option transport-type socket >> 18: option username 42fa7a62-1420-4169-ad00-53c3481dbe5b >> 19: option password b71b3c88-51e0-464c-8b09-14b661fdb4d3 >> 20: option send-gids true >> 21: end-volume >> 22: >> 23: volume backups-replicate-0 >> 24: type cluster/replicate >> 25: subvolumes backups-client-0 backups-client-1 >> 26: end-volume >> 27: >> 28: volume backups-dht >> 29: type cluster/distribute >> 30: subvolumes backups-replicate-0 >> 31: end-volume >> 32: >> 33: volume backups-write-behind >> 34: type performance/write-behind >> 35: subvolumes backups-dht >> 36: end-volume >> 37: >> 38: volume backups >> 39: type debug/io-stats >> 40: option latency-measurement off >> 41: option count-fop-hits off >> 42: subvolumes backups-write-behind >> 43: end-volume >> 44: >> 45: volume nfs-server >> 46: type nfs/server >> 47: option rpc-auth.auth-glusterfs on >> 48: option rpc-auth.auth-unix on >> 49: option rpc-auth.auth-null on >> 50: option rpc-auth.ports.insecure on >> 51: option rpc-auth-allow-insecure on >> 52: option transport-type socket >> 53: option transport.socket.listen-port 2049 >> 54: option nfs.dynamic-volumes on >> 55: option nfs.nlm on >> 56: option nfs.drc off >> 57: option rpc-auth.addr.backups.allow * >> 58: option nfs3.backups.volume-id >> 71a26ea6-632d-4a1d-8610-e782ce2a5100 >> 59: option nfs.backups.disable off >> 60: option nfs.logs.disable off >> 61: option nfs.users.disable off >> 62: subvolumes backups >> 63: end-volume >> 64: >> +------------------------------------------------------------------------------+ >> >> >> [2016-03-07 16:03:14.318157] I [MSGID: 114046] >> [client-handshake.c:1213:client_setvolume_cbk] 0-backups-client-0: >> Connected to backups-client-0, attached to remote volume >> '/zfspool/glusterfs/backups/data'. >> [2016-03-07 16:03:14.318276] I [MSGID: 114047] >> [client-handshake.c:1224:client_setvolume_cbk] 0-backups-client-0: >> Server and Client lk-version numbers are not same, reopening the fds >> [2016-03-07 16:03:14.318400] I [MSGID: 108005] >> [afr-common.c:3841:afr_notify] 0-backups-replicate-0: Subvolume >> 'backups-client-0' came back up; going online. >> [2016-03-07 16:03:14.318470] I [MSGID: 114035] >> [client-handshake.c:193:client_set_lk_version_cbk] 0-backups-client-0: >> Server lk version = 1 >> [2016-03-07 16:03:14.496642] I [rpc-clnt.c:1847:rpc_clnt_reconfig] >> 0-backups-client-1: changing port to 49152 (from 0) >> [2016-03-07 16:03:14.498394] I [MSGID: 114057] >> [client-handshake.c:1437:select_server_supported_programs] >> 0-backups-client-1: Using Program GlusterFS 3.3, Num (1298437), Version >> (330) >> [2016-03-07 16:03:14.505580] I [MSGID: 114046] >> [client-handshake.c:1213:client_setvolume_cbk] 0-backups-client-1: >> Connected to backups-client-1, attached to remote volume >> '/zfspool/glusterfs/backups/data'. >> [2016-03-07 16:03:14.505627] I [MSGID: 114047] >> [client-handshake.c:1224:client_setvolume_cbk] 0-backups-client-1: >> Server and Client lk-version numbers are not same, reopening the fds >> [2016-03-07 16:03:14.506210] I [MSGID: 114035] >> [client-handshake.c:193:client_set_lk_version_cbk] 0-backups-client-1: >> Server lk version = 1 >> [2016-03-07 16:03:14.507836] I [MSGID: 108031] >> [afr-common.c:1782:afr_local_discovery_cbk] 0-backups-replicate-0: >> selecting local read_child backups-client-0 >> >> >> >> >> On 3/6/16 9:13 PM, Jiffin Tony Thottan wrote: >>> >>> >>> On 05/03/16 07:12, Mark Selby wrote: >>>> I am trying to use GlusterFS as a general purpose NFS file server. I >>>> have tried using the FUSE client but the performance fall off vs NFS >>>> is quite large >>>> >>>> Both the client and the server are Ubuntu 14.04. >>>> >>>> I am using Gluster 3.6.9 because of the FUSE performance issues that >>>> have been reported with 3.7.8 (see >>>> https://bugzilla.redhat.com/show_bug.cgi?id=1309462) >>>> >>>> I am having serious issues with a generic NFS client as shown by the >>>> issues below. Basically most FOPs are giving me a Remote I/O error. >>>> >>>> I would not think I was 1st person to see these issues - but my >>>> Google Fu is not working. >>>> >>>> Any and all help would be much appreciated >>>> >>>> BTW - These operation against a plain Linux NFS server work fine. >>>> >>>> >>>> root at dc1strg001x /var/log 448# gluster volume status >>>> Status of volume: backups >>>> Gluster process Port Online Pid >>>> ------------------------------------------------------------------------------ >>>> >>>> >>>> Brick dc1strg001x:/zfspool/glusterfs/backups/data 49152 Y 6462 >>>> Brick dc1strg002x:/zfspool/glusterfs/backups/data 49152 Y 6382 >>>> NFS Server on localhost 2049 Y 6619 >>>> Self-heal Daemon on localhost N/A Y 6626 >>>> NFS Server on dc1strg002x 2049 Y 6502 >>>> Self-heal Daemon on dc1strg002x N/A Y 6509 >>>> >>>> >>>> root at vc1test001 /root 735# mount -o vers=3 -t nfs >>>> dc1strg001x:/backups /mnt/backups_nfs >>>> >>>> root at vc1test001 /mnt/backups_nfs 737# dd if=/dev/zero of=testfile >>>> bs=16k count=16384 >>>> 16384+0 records in >>>> 16384+0 records out >>>> 268435456 bytes (268 MB) copied, 2.46237 s, 109 MB/s >>>> >>>> root at vc1test001 /mnt/backups_nfs 738# rm testfile >>>> >>>> root at vc1test001 /mnt/backups_nfs 739# dd if=/dev/zero of=testfile >>>> bs=16k count=16384 >>>> dd: failed to open ~testfile~: Remote I/O error >>>> >>>> root at vc1test001 /var/tmp 743# rsync -av testfile /mnt/backups_nfs/ >>>> sending incremental file list >>>> testfile >>>> rsync: mkstemp "/mnt/backups_nfs/.testfile.bzg47C" failed: Remote I/O >>>> error (121) >>>> >>>> sent 1,074,004,056 bytes received 121 bytes 165,231,411.85 bytes/sec >>>> total size is 1,073,741,824 speedup is 1.00 >>>> rsync error: some files/attrs were not transferred (see previous >>>> errors) (code 23) at main.c(1183) [sender=3.1.0] >>>> >>> >>> Can you please provide the volume configuration(gluster vol info ) >>> and log file for nfs server which u mounted (/var/log/glusterfs) >>> >>> -- >>> Jiffin >>>> _______________________________________________ >>>> Gluster-users mailing list >>>> Gluster-users at gluster.org >>>> http://www.gluster.org/mailman/listinfo/gluster-users >>> >> >> _______________________________________________ >> Gluster-users mailing list >> Gluster-users at gluster.org >> http://www.gluster.org/mailman/listinfo/gluster-users
Mark Selby
2016-Mar-10 02:41 UTC
[Gluster-users] NFS Client issues with Gluster Server 3.6.9
The problem turns out to be with ZFS I use ZFS on linux as the underlying filesystem and as per the docs you need to set zfs set acltype=posixacl on all the pools you are exporting as NFS. I did not do this and it causes chaos. Once I did this the NFS issues go away and all is good. Thanks everyone! On 3/8/16 6:42 AM, Soumya Koduri wrote:> The log file didn't have any errors logged. Please check the NFS > client logs in '/var/log/messages' or using dmesg and brick logs as well. > > Probably strace or packet trace could help too. You could use the > below command to capture the pkt trace while running the I/Os on the > node where gluster-nfs server is running : > > $ tcpdump -i any -s 0 -w /var/tmp/nfs.pcap tcp and not port 22 > > Check the file later to see what operation had failed (using filters: > nfs, glusterfs). > > Thanks, > Soumya > > > On 03/07/2016 09:41 PM, Mark Selby wrote: >> Here are the logs that you requested >> >> Please let me know if I can send you anything else. >> >> I really appreciate you taking a look at this - thanks! >> >> >> root at dc1strg001x /root 547# gluster vol info backups >> >> Volume Name: backups >> Type: Replicate >> Volume ID: 71a26ea6-632d-4a1d-8610-e782ce2a5100 >> Status: Started >> Number of Bricks: 1 x 2 = 2 >> Transport-type: tcp >> Bricks: >> Brick1: dc1strg001x:/zfspool/glusterfs/backups/data >> Brick2: dc1strg002x:/zfspool/glusterfs/backups/data >> Options Reconfigured: >> nfs.disable: off >> >> >> root at dc1strg001x /var/log/glusterfs 551# cat nfs.log >> [2016-03-07 16:03:14.257919] I [MSGID: 100030] [glusterfsd.c:2318:main] >> 0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version 3.7.6 >> (args: /usr/sbin/glusterfs -s localhost --volfile-id gluster/nfs -p >> /var/lib/glusterd/nfs/run/nfs.pid -l /var/log/glusterfs/nfs.log -S >> /var/run/gluster/ad38be3bd1baece29e1b672e6659ae60.socket) >> [2016-03-07 16:03:14.267862] I [MSGID: 101190] >> [event-epoll.c:632:event_dispatch_epoll_worker] 0-epoll: Started thread >> with index 1 >> [2016-03-07 16:03:14.273283] I >> [rpcsvc.c:2215:rpcsvc_set_outstanding_rpc_limit] 0-rpc-service: >> Configured rpc.outstanding-rpc-limit with value 16 >> [2016-03-07 16:03:14.284154] W [MSGID: 112153] >> [mount3.c:3929:mnt3svc_init] 0-nfs-mount: Exports auth has been >> disabled! >> [2016-03-07 16:03:14.306163] I [rpc-drc.c:694:rpcsvc_drc_init] >> 0-rpc-service: DRC is turned OFF >> [2016-03-07 16:03:14.306216] I [MSGID: 112110] [nfs.c:1494:init] 0-nfs: >> NFS service started >> [2016-03-07 16:03:14.312901] I [MSGID: 101190] >> [event-epoll.c:632:event_dispatch_epoll_worker] 0-epoll: Started thread >> with index 2 >> [2016-03-07 16:03:14.314078] W [graph.c:357:_log_if_unknown_option] >> 0-nfs-server: option 'rpc-auth.auth-glusterfs' is not recognized >> [2016-03-07 16:03:14.314137] W [graph.c:357:_log_if_unknown_option] >> 0-nfs-server: option 'rpc-auth-allow-insecure' is not recognized >> [2016-03-07 16:03:14.314185] W [graph.c:357:_log_if_unknown_option] >> 0-nfs-server: option 'transport-type' is not recognized >> [2016-03-07 16:03:14.314270] I [MSGID: 114020] [client.c:2118:notify] >> 0-backups-client-0: parent translators are ready, attempting connect on >> transport >> [2016-03-07 16:03:14.315341] I [MSGID: 114020] [client.c:2118:notify] >> 0-backups-client-1: parent translators are ready, attempting connect on >> transport >> [2016-03-07 16:03:14.315923] I [rpc-clnt.c:1847:rpc_clnt_reconfig] >> 0-backups-client-0: changing port to 49152 (from 0) >> Final graph: >> +------------------------------------------------------------------------------+ >> >> >> 1: volume backups-client-0 >> 2: type protocol/client >> 3: option ping-timeout 42 >> 4: option remote-host dc1strg001x >> 5: option remote-subvolume /zfspool/glusterfs/backups/data >> 6: option transport-type socket >> 7: option username 42fa7a62-1420-4169-ad00-53c3481dbe5b >> 8: option password b71b3c88-51e0-464c-8b09-14b661fdb4d3 >> 9: option send-gids true >> 10: end-volume >> 11: >> 12: volume backups-client-1 >> 13: type protocol/client >> 14: option ping-timeout 42 >> 15: option remote-host dc1strg002x >> [2016-03-07 16:03:14.317412] I [MSGID: 114057] >> [client-handshake.c:1437:select_server_supported_programs] >> 0-backups-client-0: Using Program GlusterFS 3.3, Num (1298437), Version >> (330) >> 16: option remote-subvolume /zfspool/glusterfs/backups/data >> 17: option transport-type socket >> 18: option username 42fa7a62-1420-4169-ad00-53c3481dbe5b >> 19: option password b71b3c88-51e0-464c-8b09-14b661fdb4d3 >> 20: option send-gids true >> 21: end-volume >> 22: >> 23: volume backups-replicate-0 >> 24: type cluster/replicate >> 25: subvolumes backups-client-0 backups-client-1 >> 26: end-volume >> 27: >> 28: volume backups-dht >> 29: type cluster/distribute >> 30: subvolumes backups-replicate-0 >> 31: end-volume >> 32: >> 33: volume backups-write-behind >> 34: type performance/write-behind >> 35: subvolumes backups-dht >> 36: end-volume >> 37: >> 38: volume backups >> 39: type debug/io-stats >> 40: option latency-measurement off >> 41: option count-fop-hits off >> 42: subvolumes backups-write-behind >> 43: end-volume >> 44: >> 45: volume nfs-server >> 46: type nfs/server >> 47: option rpc-auth.auth-glusterfs on >> 48: option rpc-auth.auth-unix on >> 49: option rpc-auth.auth-null on >> 50: option rpc-auth.ports.insecure on >> 51: option rpc-auth-allow-insecure on >> 52: option transport-type socket >> 53: option transport.socket.listen-port 2049 >> 54: option nfs.dynamic-volumes on >> 55: option nfs.nlm on >> 56: option nfs.drc off >> 57: option rpc-auth.addr.backups.allow * >> 58: option nfs3.backups.volume-id >> 71a26ea6-632d-4a1d-8610-e782ce2a5100 >> 59: option nfs.backups.disable off >> 60: option nfs.logs.disable off >> 61: option nfs.users.disable off >> 62: subvolumes backups >> 63: end-volume >> 64: >> +------------------------------------------------------------------------------+ >> >> >> [2016-03-07 16:03:14.318157] I [MSGID: 114046] >> [client-handshake.c:1213:client_setvolume_cbk] 0-backups-client-0: >> Connected to backups-client-0, attached to remote volume >> '/zfspool/glusterfs/backups/data'. >> [2016-03-07 16:03:14.318276] I [MSGID: 114047] >> [client-handshake.c:1224:client_setvolume_cbk] 0-backups-client-0: >> Server and Client lk-version numbers are not same, reopening the fds >> [2016-03-07 16:03:14.318400] I [MSGID: 108005] >> [afr-common.c:3841:afr_notify] 0-backups-replicate-0: Subvolume >> 'backups-client-0' came back up; going online. >> [2016-03-07 16:03:14.318470] I [MSGID: 114035] >> [client-handshake.c:193:client_set_lk_version_cbk] 0-backups-client-0: >> Server lk version = 1 >> [2016-03-07 16:03:14.496642] I [rpc-clnt.c:1847:rpc_clnt_reconfig] >> 0-backups-client-1: changing port to 49152 (from 0) >> [2016-03-07 16:03:14.498394] I [MSGID: 114057] >> [client-handshake.c:1437:select_server_supported_programs] >> 0-backups-client-1: Using Program GlusterFS 3.3, Num (1298437), Version >> (330) >> [2016-03-07 16:03:14.505580] I [MSGID: 114046] >> [client-handshake.c:1213:client_setvolume_cbk] 0-backups-client-1: >> Connected to backups-client-1, attached to remote volume >> '/zfspool/glusterfs/backups/data'. >> [2016-03-07 16:03:14.505627] I [MSGID: 114047] >> [client-handshake.c:1224:client_setvolume_cbk] 0-backups-client-1: >> Server and Client lk-version numbers are not same, reopening the fds >> [2016-03-07 16:03:14.506210] I [MSGID: 114035] >> [client-handshake.c:193:client_set_lk_version_cbk] 0-backups-client-1: >> Server lk version = 1 >> [2016-03-07 16:03:14.507836] I [MSGID: 108031] >> [afr-common.c:1782:afr_local_discovery_cbk] 0-backups-replicate-0: >> selecting local read_child backups-client-0 >> >> >> >> >> On 3/6/16 9:13 PM, Jiffin Tony Thottan wrote: >>> >>> >>> On 05/03/16 07:12, Mark Selby wrote: >>>> I am trying to use GlusterFS as a general purpose NFS file server. I >>>> have tried using the FUSE client but the performance fall off vs NFS >>>> is quite large >>>> >>>> Both the client and the server are Ubuntu 14.04. >>>> >>>> I am using Gluster 3.6.9 because of the FUSE performance issues that >>>> have been reported with 3.7.8 (see >>>> https://bugzilla.redhat.com/show_bug.cgi?id=1309462) >>>> >>>> I am having serious issues with a generic NFS client as shown by the >>>> issues below. Basically most FOPs are giving me a Remote I/O error. >>>> >>>> I would not think I was 1st person to see these issues - but my >>>> Google Fu is not working. >>>> >>>> Any and all help would be much appreciated >>>> >>>> BTW - These operation against a plain Linux NFS server work fine. >>>> >>>> >>>> root at dc1strg001x /var/log 448# gluster volume status >>>> Status of volume: backups >>>> Gluster process Port Online Pid >>>> ------------------------------------------------------------------------------ >>>> >>>> >>>> Brick dc1strg001x:/zfspool/glusterfs/backups/data 49152 Y 6462 >>>> Brick dc1strg002x:/zfspool/glusterfs/backups/data 49152 Y 6382 >>>> NFS Server on localhost 2049 Y 6619 >>>> Self-heal Daemon on localhost N/A Y 6626 >>>> NFS Server on dc1strg002x 2049 Y 6502 >>>> Self-heal Daemon on dc1strg002x N/A Y 6509 >>>> >>>> >>>> root at vc1test001 /root 735# mount -o vers=3 -t nfs >>>> dc1strg001x:/backups /mnt/backups_nfs >>>> >>>> root at vc1test001 /mnt/backups_nfs 737# dd if=/dev/zero of=testfile >>>> bs=16k count=16384 >>>> 16384+0 records in >>>> 16384+0 records out >>>> 268435456 bytes (268 MB) copied, 2.46237 s, 109 MB/s >>>> >>>> root at vc1test001 /mnt/backups_nfs 738# rm testfile >>>> >>>> root at vc1test001 /mnt/backups_nfs 739# dd if=/dev/zero of=testfile >>>> bs=16k count=16384 >>>> dd: failed to open ~testfile~: Remote I/O error >>>> >>>> root at vc1test001 /var/tmp 743# rsync -av testfile /mnt/backups_nfs/ >>>> sending incremental file list >>>> testfile >>>> rsync: mkstemp "/mnt/backups_nfs/.testfile.bzg47C" failed: Remote I/O >>>> error (121) >>>> >>>> sent 1,074,004,056 bytes received 121 bytes 165,231,411.85 bytes/sec >>>> total size is 1,073,741,824 speedup is 1.00 >>>> rsync error: some files/attrs were not transferred (see previous >>>> errors) (code 23) at main.c(1183) [sender=3.1.0] >>>> >>> >>> Can you please provide the volume configuration(gluster vol info ) >>> and log file for nfs server which u mounted (/var/log/glusterfs) >>> >>> -- >>> Jiffin >>>> _______________________________________________ >>>> Gluster-users mailing list >>>> Gluster-users at gluster.org >>>> http://www.gluster.org/mailman/listinfo/gluster-users >>> >> >> _______________________________________________ >> Gluster-users mailing list >> Gluster-users at gluster.org >> http://www.gluster.org/mailman/listinfo/gluster-users