Bug 812844 - cannot mount subdirectory on Solaris client
Summary: cannot mount subdirectory on Solaris client
Keywords:
Status: CLOSED NEXTRELEASE
Alias: None
Product: GlusterFS
Classification: Community
Component: nfs
Version: 3.2.5
Hardware: x86_64
OS: Solaris
unspecified
high
Target Milestone: ---
Assignee: Rajesh
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-04-16 12:24 UTC by Anthony
Modified: 2013-07-04 22:44 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-07-23 07:26:36 UTC
Regression: ---
Mount Type: nfs
Documentation: ---
CRM:
Verified Versions:
Embargoed:

Attachments (Terms of Use)

Description Anthony 2012-04-16 12:24:40 UTC 
I'm unable to mount Subdirectory on Solaris client (sunOS 5.10)

gluster volume info

Volume Name: athena
Type: Replicate
Status: Started
Number of Bricks: 2
Transport-type: tcp
Bricks:
Brick1: ylal3020:/users/export
Brick2: ylal3030:/users/export
Options Reconfigured:
diagnostics.client-log-level: TRACE
diagnostics.brick-log-level: TRACE
performance.io-thread-count: 64
nfs.port: 2049
performance.cache-refresh-timeout: 60
performance.cache-size: 4GB
network.ping-timeout: 10
performance.cache-min-file-size: 0
performance.cache-max-file-size: 100MB


Solaris client : 
# mount -o proto=tcp,vers=3,llock,hard,bg,timeo=600,intr,rsize=32768,wsize=32768 nfs://ylal3030/athena/test /users/glusterfs_mnt
nfs mount: ylal3030: : RPC: Program not registered



nfs.log :

[2012-04-16 14:07:05.208791] D [client.c:1856:client_rpc_notify] 0-athena-client-1: got RPC_CLNT_CONNECT
[2012-04-16 14:07:05.208845] T [rpc-clnt.c:1224:rpc_clnt_record] 0-athena-client-1: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:05.208875] T [rpc-clnt.c:1125:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 136, payload: 8, rpc hdr: 128
[2012-04-16 14:07:05.209125] T [socket.c:1973:socket_connect] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_handshake+0x14f) [0x2aaaaaad48af] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_submit_request+0x251) [0x2aaaaaabbf41] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_submit+0x3d4) [0x2b4bf0d973c4]))) 0-athena-client-1: connect () called on transport already connected
[2012-04-16 14:07:05.209180] T [rpc-clnt.c:1429:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x1x Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (athena-client-1)
[2012-04-16 14:07:05.209210] D [client-handshake.c:179:client_start_ping] 0-athena-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
[2012-04-16 14:07:05.209243] D [client.c:1856:client_rpc_notify] 0-athena-client-0: got RPC_CLNT_CONNECT
[2012-04-16 14:07:05.209262] T [rpc-clnt.c:1224:rpc_clnt_record] 0-athena-client-0: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:05.209278] T [rpc-clnt.c:1125:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 136, payload: 8, rpc hdr: 128
[2012-04-16 14:07:05.209320] T [socket.c:1973:socket_connect] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_handshake+0x14f) [0x2aaaaaad48af] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_submit_request+0x251) [0x2aaaaaabbf41] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_submit+0x3d4) [0x2b4bf0d973c4]))) 0-athena-client-0: connect () called on transport already connected
[2012-04-16 14:07:05.209350] T [rpc-clnt.c:1429:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x1x Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (athena-client-0)
[2012-04-16 14:07:05.209367] D [client-handshake.c:179:client_start_ping] 0-athena-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
[2012-04-16 14:07:05.209500] T [rpc-clnt.c:638:rpc_clnt_reply_init] 0-athena-client-1: received rpc message (RPC XID: 0x1x Program: GF-DUMP, ProgVers: 1, Proc: 1) from rpc-transport (athena-client-1)
[2012-04-16 14:07:05.209537] D [client-handshake.c:1124:server_has_portmap] 0-athena-client-1: detected portmapper on server
[2012-04-16 14:07:05.209569] T [rpc-clnt.c:1224:rpc_clnt_record] 0-athena-client-1: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:05.209589] T [rpc-clnt.c:1125:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 148, payload: 20, rpc hdr: 128
[2012-04-16 14:07:05.209634] T [socket.c:1973:socket_connect] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_query_portmap+0x26d) [0x2aaaaaad57dd] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_submit_request+0x251) [0x2aaaaaabbf41] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_submit+0x3d4) [0x2b4bf0d973c4]))) 0-athena-client-1: connect () called on transport already connected
[2012-04-16 14:07:05.209687] T [rpc-clnt.c:1429:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x2x Program: Gluster Portmap, ProgVers: 1, Proc: 1) to rpc-transport (athena-client-1)
[2012-04-16 14:07:05.209711] D [client-handshake.c:179:client_start_ping] 0-athena-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
[2012-04-16 14:07:05.209783] T [rpc-clnt.c:638:rpc_clnt_reply_init] 0-athena-client-1: received rpc message (RPC XID: 0x2x Program: Gluster Portmap, ProgVers: 1, Proc: 1) from rpc-transport (athena-client-1)
[2012-04-16 14:07:05.209810] I [rpc-clnt.c:1536:rpc_clnt_reconfig] 0-athena-client-1: changing port to 24009 (from 0)
[2012-04-16 14:07:05.209836] T [rpc-clnt.c:399:rpc_clnt_reconnect] 0-athena-client-1: attempting reconnect
[2012-04-16 14:07:05.209879] T [socket.c:1973:socket_connect] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_handle_reply+0xa2) [0x2b4bf0d96712] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_query_portmap_cbk+0x24f) [0x2aaaaaad685f] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_reconnect+0xef) [0x2b4bf0d95a7f]))) 0-athena-client-1: connect () called on transport already connected
[2012-04-16 14:07:05.209904] D [socket.c:193:__socket_rwv] 0-athena-client-1: EOF from peer 10.82.211.18:24007
[2012-04-16 14:07:05.209927] D [socket.c:1494:__socket_proto_state_machine] 0-athena-client-1: reading from socket failed. Error (Transport endpoint is not connected), peer (10.82.211.18:24007)
[2012-04-16 14:07:05.209941] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:07:05.209962] T [rpc-clnt.c:495:rpc_clnt_connection_cleanup] 0-athena-client-1: cleaning up state in transport object 0x57b470
[2012-04-16 14:07:05.209980] D [client.c:1901:client_rpc_notify] 0-athena-client-1: disconnected (skipped notify)
[2012-04-16 14:07:06.195036] T [rpc-clnt.c:638:rpc_clnt_reply_init] 0-athena-client-0: received rpc message (RPC XID: 0x1x Program: GF-DUMP, ProgVers: 1, Proc: 1) from rpc-transport (athena-client-0)
[2012-04-16 14:07:06.195080] D [client-handshake.c:1124:server_has_portmap] 0-athena-client-0: detected portmapper on server
[2012-04-16 14:07:06.195110] T [rpc-clnt.c:1224:rpc_clnt_record] 0-athena-client-0: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:06.195128] T [rpc-clnt.c:1125:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 148, payload: 20, rpc hdr: 128
[2012-04-16 14:07:06.195187] T [socket.c:1973:socket_connect] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_query_portmap+0x26d) [0x2aaaaaad57dd] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_submit_request+0x251) [0x2aaaaaabbf41] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_submit+0x3d4) [0x2b4bf0d973c4]))) 0-athena-client-0: connect () called on transport already connected
[2012-04-16 14:07:06.195217] T [rpc-clnt.c:1429:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x2x Program: Gluster Portmap, ProgVers: 1, Proc: 1) to rpc-transport (athena-client-0)
[2012-04-16 14:07:06.195236] D [client-handshake.c:179:client_start_ping] 0-athena-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
[2012-04-16 14:07:06.195444] T [rpc-clnt.c:638:rpc_clnt_reply_init] 0-athena-client-0: received rpc message (RPC XID: 0x2x Program: Gluster Portmap, ProgVers: 1, Proc: 1) from rpc-transport (athena-client-0)
[2012-04-16 14:07:06.195471] I [rpc-clnt.c:1536:rpc_clnt_reconfig] 0-athena-client-0: changing port to 24009 (from 0)
[2012-04-16 14:07:06.195500] T [rpc-clnt.c:399:rpc_clnt_reconnect] 0-athena-client-0: attempting reconnect
[2012-04-16 14:07:06.195542] T [socket.c:1973:socket_connect] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_handle_reply+0xa2) [0x2b4bf0d96712] (-->/usr/local/lib//glusterfs/3.2.5/xlator/protocol/client.so(client_query_portmap_cbk+0x24f) [0x2aaaaaad685f] (-->/usr/local/lib/libgfrpc.so.0(rpc_clnt_reconnect+0xef) [0x2b4bf0d95a7f]))) 0-athena-client-0: connect () called on transport already connected
[2012-04-16 14:07:06.195606] D [socket.c:193:__socket_rwv] 0-athena-client-0: EOF from peer 10.80.48.26:24007
[2012-04-16 14:07:06.195628] D [socket.c:1494:__socket_proto_state_machine] 0-athena-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (10.80.48.26:24007)
[2012-04-16 14:07:06.195642] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:07:06.195665] T [rpc-clnt.c:495:rpc_clnt_connection_cleanup] 0-athena-client-0: cleaning up state in transport object 0x57c140
[2012-04-16 14:07:06.195704] D [client.c:1901:client_rpc_notify] 0-athena-client-0: disconnected (skipped notify)
[2012-04-16 14:07:07.419433] T [rpcsvc.c:689:nfs_rpcsvc_conn_init] 0-nfsrpc: tx pool: 525
[2012-04-16 14:07:07.419561] T [rpcsvc.c:696:nfs_rpcsvc_conn_init] 0-nfsrpc: rx pool: 525
[2012-04-16 14:07:07.419851] D [rpcsvc.c:712:nfs_rpcsvc_conn_init] 0-nfsrpc: New connection inited: sockfd: 6
[2012-04-16 14:07:07.419881] D [rpcsvc.c:2747:nfs_rpcsvc_conn_listening_handler] 0-nfsrpc: New Connection
[2012-04-16 14:07:07.419907] T [rpcsvc.c:2547:nfs_rpcsvc_conn_data_poll_in] 0-nfsrpc: conn: 0x53dc28, readsize: 4, dataread:4
[2012-04-16 14:07:07.419924] T [rpcsvc.c:1119:nfs_rpcsvc_record_read_complete_fraghdr] 0-nfsrpc: Received fragment size: 92
[2012-04-16 14:07:07.419938] T [rpcsvc.c:1126:nfs_rpcsvc_record_read_complete_fraghdr] 0-nfsrpc: Regular RPC header, remaining: 92
[2012-04-16 14:07:07.419955] T [rpcsvc.c:2547:nfs_rpcsvc_conn_data_poll_in] 0-nfsrpc: conn: 0x53dc28, readsize: 92, dataread:92
[2012-04-16 14:07:07.419969] T [rpcsvc.c:2484:nfs_rpcsvc_record_update_state] 0-nfsrpc: Regular frag
[2012-04-16 14:07:07.419983] T [rpcsvc.c:1217:nfs_rpcsvc_record_read_complete_frag] 0-nfsrpc: Fragment remaining: 0
[2012-04-16 14:07:07.419995] T [rpcsvc.c:2506:nfs_rpcsvc_record_update_state] 0-nfsrpc: Full Record Received.
[2012-04-16 14:07:07.420012] T [rpcsvc-auth.c:256:nfs_rpcsvc_auth_request_init] 0-nfsrpc: Auth handler: AUTH_UNIX
[2012-04-16 14:07:07.420026] D [rpcsvc.c:1956:nfs_rpcsvc_request_create] 0-nfsrpc: RPC XID: 4f8a53f0, Ver: 2, Program: 100003, ProgVers: 3, Proc: 3
[2012-04-16 14:07:07.420042] T [rpcsvc.c:1340:__nfs_rpcsvc_program_actor] 0-nfsrpc: RPC Program found
[2012-04-16 14:07:07.420058] T [auth-unix.c:72:nfs_auth_unix_authenticate] 0-nfsrpc: Auth Info: machine name: ylas1420, uid: 0, gid: 3
[2012-04-16 14:07:07.420072] D [rpcsvc.c:1373:nfs_rpcsvc_program_actor] 0-nfsrpc: Actor found: NFS3 - LOOKUP
[2012-04-16 14:07:07.420119] D [nfs3-helpers.c:2178:nfs3_log_fh_entry_call] 0-nfs-nfsv3: XID: 4f8a53f0, LOOKUP: args: FH: hashcount 0, exportid 00000000-0000-0000-0000-000000000000, gfid 00000000-0000-0000-0000-000000000000, name: athena/test
[2012-04-16 14:07:07.420141] T [nfs-common.c:99:nfs_mntpath_to_xlator] 0-nfs: Subvolume search: athena/test
[2012-04-16 14:07:07.420164] D [nfs3-helpers.c:2298:nfs3_log_common_res] 0-nfs-nfsv3: XID: 4f8a53f0, LOOKUP: NFS: 2(No such file or directory), POSIX: 14(Bad address)
[2012-04-16 14:07:07.420191] T [rpcsvc.c:1691:nfs_rpcsvc_submit_generic] 0-nfsrpc: Tx message: 8
[2012-04-16 14:07:07.420208] T [rpcsvc.c:1472:nfs_rpcsvc_record_build_header] 0-nfsrpc: Reply fraglen 32, payload: 8, rpc hdr: 24
[2012-04-16 14:07:07.420223] T [rpcsvc.c:1509:nfs_rpcsvc_conn_submit] 0-nfsrpc: Tx Header: 28, payload: 8
[2012-04-16 14:07:07.420244] T [rpcsvc.c:2594:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: First Tx Buf
[2012-04-16 14:07:07.420264] T [rpcsvc.c:2605:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: conn: 0x53dc28, Tx request: 28, Tx sent: 28
[2012-04-16 14:07:07.420280] T [rpcsvc.c:2601:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: Last Tx Buf
[2012-04-16 14:07:07.420297] T [rpcsvc.c:2605:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: conn: 0x53dc28, Tx request: 8, Tx sent: 8
[2012-04-16 14:07:07.432065] T [rpcsvc.c:2547:nfs_rpcsvc_conn_data_poll_in] 0-nfsrpc: conn: 0x53dc28, readsize: 4, dataread:0
[2012-04-16 14:07:07.432101] T [rpcsvc.c:2560:nfs_rpcsvc_conn_data_poll_err] 0-nfsrpc: Received error event
[2012-04-16 14:07:07.432154] D [rpcsvc.c:762:__nfs_rpcsvc_conn_deinit] 0-nfsrpc: Connection de-activated: sockfd: 6
[2012-04-16 14:07:07.432222] D [rpcsvc.c:737:nfs_rpcsvc_conn_destroy] 0-nfsrpc: Connection destroyed
[2012-04-16 14:07:07.458858] T [rpcsvc.c:689:nfs_rpcsvc_conn_init] 0-nfsrpc: tx pool: 525
[2012-04-16 14:07:07.458914] T [rpcsvc.c:696:nfs_rpcsvc_conn_init] 0-nfsrpc: rx pool: 525
[2012-04-16 14:07:07.459142] D [rpcsvc.c:712:nfs_rpcsvc_conn_init] 0-nfsrpc: New connection inited: sockfd: 6
[2012-04-16 14:07:07.459168] D [rpcsvc.c:2747:nfs_rpcsvc_conn_listening_handler] 0-nfsrpc: New Connection
[2012-04-16 14:07:07.459187] T [rpcsvc.c:2547:nfs_rpcsvc_conn_data_poll_in] 0-nfsrpc: conn: 0x53dc28, readsize: 4, dataread:4
[2012-04-16 14:07:07.459202] T [rpcsvc.c:1119:nfs_rpcsvc_record_read_complete_fraghdr] 0-nfsrpc: Received fragment size: 92
[2012-04-16 14:07:07.459215] T [rpcsvc.c:1126:nfs_rpcsvc_record_read_complete_fraghdr] 0-nfsrpc: Regular RPC header, remaining: 92
[2012-04-16 14:07:07.459231] T [rpcsvc.c:2547:nfs_rpcsvc_conn_data_poll_in] 0-nfsrpc: conn: 0x53dc28, readsize: 92, dataread:92
[2012-04-16 14:07:07.459245] T [rpcsvc.c:2484:nfs_rpcsvc_record_update_state] 0-nfsrpc: Regular frag
[2012-04-16 14:07:07.459258] T [rpcsvc.c:1217:nfs_rpcsvc_record_read_complete_frag] 0-nfsrpc: Fragment remaining: 0
[2012-04-16 14:07:07.459271] T [rpcsvc.c:2506:nfs_rpcsvc_record_update_state] 0-nfsrpc: Full Record Received.
[2012-04-16 14:07:07.459285] T [rpcsvc-auth.c:256:nfs_rpcsvc_auth_request_init] 0-nfsrpc: Auth handler: AUTH_UNIX
[2012-04-16 14:07:07.459298] D [rpcsvc.c:1956:nfs_rpcsvc_request_create] 0-nfsrpc: RPC XID: 4f8afdd1, Ver: 2, Program: 100003, ProgVers: 3, Proc: 3
[2012-04-16 14:07:07.459312] T [rpcsvc.c:1340:__nfs_rpcsvc_program_actor] 0-nfsrpc: RPC Program found
[2012-04-16 14:07:07.459326] T [auth-unix.c:72:nfs_auth_unix_authenticate] 0-nfsrpc: Auth Info: machine name: ylas1420, uid: 0, gid: 3
[2012-04-16 14:07:07.459340] D [rpcsvc.c:1373:nfs_rpcsvc_program_actor] 0-nfsrpc: Actor found: NFS3 - LOOKUP
[2012-04-16 14:07:07.459360] D [nfs3-helpers.c:2178:nfs3_log_fh_entry_call] 0-nfs-nfsv3: XID: 4f8afdd1, LOOKUP: args: FH: hashcount 0, exportid 00000000-0000-0000-0000-000000000000, gfid 00000000-0000-0000-0000-000000000000, name: athena/test
[2012-04-16 14:07:07.459376] T [nfs-common.c:99:nfs_mntpath_to_xlator] 0-nfs: Subvolume search: athena/test
[2012-04-16 14:07:07.459394] D [nfs3-helpers.c:2298:nfs3_log_common_res] 0-nfs-nfsv3: XID: 4f8afdd1, LOOKUP: NFS: 2(No such file or directory), POSIX: 14(Bad address)
[2012-04-16 14:07:07.459410] T [rpcsvc.c:1691:nfs_rpcsvc_submit_generic] 0-nfsrpc: Tx message: 8
[2012-04-16 14:07:07.459425] T [rpcsvc.c:1472:nfs_rpcsvc_record_build_header] 0-nfsrpc: Reply fraglen 32, payload: 8, rpc hdr: 24
[2012-04-16 14:07:07.459439] T [rpcsvc.c:1509:nfs_rpcsvc_conn_submit] 0-nfsrpc: Tx Header: 28, payload: 8
[2012-04-16 14:07:07.459456] T [rpcsvc.c:2594:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: First Tx Buf
[2012-04-16 14:07:07.459474] T [rpcsvc.c:2605:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: conn: 0x53dc28, Tx request: 28, Tx sent: 28
[2012-04-16 14:07:07.459490] T [rpcsvc.c:2601:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: Last Tx Buf
[2012-04-16 14:07:07.459507] T [rpcsvc.c:2605:__nfs_rpcsvc_conn_data_poll_out] 0-nfsrpc: conn: 0x53dc28, Tx request: 8, Tx sent: 8






log/glusterfs/bricks/users-export.log : 

[2012-04-16 14:06:56.834374] D [io-stats.c:2398:iostats_configure_options] 0-/users/export: Returning 0
[2012-04-16 14:06:56.834385] D [xlator.c:1516:xlator_reconfigure_rec] 0-/users/export: reconfigured
[2012-04-16 14:06:56.834427] D [server.c:614:reconfigure] 0-: returning 0
[2012-04-16 14:06:56.834440] D [glusterfsd-mgmt.c:661:mgmt_getspec_cbk] 0-glusterfsd-mgmt: No need to re-load volfile, reconfigure done
[2012-04-16 14:06:56.842632] D [socket.c:193:__socket_rwv] 0-tcp.athena-server: EOF from peer 10.80.48.26:1018
[2012-04-16 14:06:56.842681] W [socket.c:1494:__socket_proto_state_machine] 0-tcp.athena-server: reading from socket failed. Error (Transport endpoint is not connected), peer (10.80.48.26:1018)
[2012-04-16 14:06:56.842698] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:06:56.842749] I [server.c:438:server_rpc_notify] 0-athena-server: disconnected connection from 10.80.48.26:1018
[2012-04-16 14:06:56.842775] I [server-helpers.c:783:server_connection_destroy] 0-athena-server: destroyed connection of ylal3020-460-2012/01/26-17:30:39:269161-athena-client-1
[2012-04-16 14:06:56.842792] T [socket.c:2657:fini] 0-tcp.athena-server: transport 0x558e20 destroyed
[2012-04-16 14:07:00.880877] T [socket.c:379:__socket_nodelay] 0-: NODELAY enabled for socket 13
[2012-04-16 14:07:00.880936] T [socket.c:433:__socket_keepalive] 0-: Keep-alive enabled for socket 13, interval 2, idle: 20
[2012-04-16 14:07:00.883266] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.883307] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.883322] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x3, Ver: 2, Program: 123451501, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.883340] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:00.883356] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GF-DUMP - DUMP
[2012-04-16 14:07:00.883375] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 136
[2012-04-16 14:07:00.883391] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 160, payload: 136, rpc hdr: 24
[2012-04-16 14:07:00.883426] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x3x, Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.885565] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.885583] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.885596] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x4, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.885611] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:00.885626] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - SETVOLUME
[2012-04-16 14:07:00.885685] D [addr.c:211:gf_auth] 0-/users/export: allowed = "*", received addr = "10.82.211.18"
[2012-04-16 14:07:00.885738] I [server-handshake.c:542:server_setvolume] 0-athena-server: accepted client from 10.82.211.18:1017 (version: 3.2.5)
[2012-04-16 14:07:00.885764] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 140
[2012-04-16 14:07:00.885780] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 164, payload: 140, rpc hdr: 24
[2012-04-16 14:07:00.885810] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x4x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.887528] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.887548] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.887562] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x5, Ver: 2, Program: 1298437, ProgVers: 310, Proc: 27) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.887578] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 1, uid: 0, gid: 0, owner: 1
[2012-04-16 14:07:00.887592] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 3.2.5 - LOOKUP
[2012-04-16 14:07:00.887625] T [server-resolve.c:127:resolve_loc_touchup] 0-athena-server: return value inode_path 1
[2012-04-16 14:07:00.887674] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.887693] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.887706] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x6, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 3) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.887721] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:00.887736] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - PING
[2012-04-16 14:07:00.887755] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2012-04-16 14:07:00.887771] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2012-04-16 14:07:00.887798] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x6x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 3) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.887853] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 380
[2012-04-16 14:07:00.887901] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 404, payload: 380, rpc hdr: 24
[2012-04-16 14:07:00.887940] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x5x, Program: GlusterFS 3.2.5, ProgVers: 310, Proc: 27) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.919330] T [socket.c:379:__socket_nodelay] 0-: NODELAY enabled for socket 15
[2012-04-16 14:07:00.919368] T [socket.c:433:__socket_keepalive] 0-: Keep-alive enabled for socket 15, interval 2, idle: 20
[2012-04-16 14:07:00.919514] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.919537] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.919551] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x3, Ver: 2, Program: 123451501, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.919567] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:00.919581] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GF-DUMP - DUMP
[2012-04-16 14:07:00.919598] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 136
[2012-04-16 14:07:00.919612] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 160, payload: 136, rpc hdr: 24
[2012-04-16 14:07:00.919657] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x3x, Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.919884] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.919904] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.919917] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x4, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.919933] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:00.919946] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - SETVOLUME
[2012-04-16 14:07:00.919988] D [addr.c:211:gf_auth] 0-/users/export: allowed = "*", received addr = "10.80.48.26"
[2012-04-16 14:07:00.920007] I [server-handshake.c:542:server_setvolume] 0-athena-server: accepted client from 10.80.48.26:1017 (version: 3.2.5)
[2012-04-16 14:07:00.920028] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 140
[2012-04-16 14:07:00.920043] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 164, payload: 140, rpc hdr: 24
[2012-04-16 14:07:00.920065] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x4x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.920509] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.920529] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.920542] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x5, Ver: 2, Program: 1298437, ProgVers: 310, Proc: 27) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.920557] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 1, uid: 0, gid: 0, owner: 1
[2012-04-16 14:07:00.920571] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 3.2.5 - LOOKUP
[2012-04-16 14:07:00.920600] T [server-resolve.c:127:resolve_loc_touchup] 0-athena-server: return value inode_path 1
[2012-04-16 14:07:00.920638] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1017
[2012-04-16 14:07:00.920656] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:00.920669] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x6, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 3) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.920684] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:00.920698] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - PING
[2012-04-16 14:07:00.920713] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2012-04-16 14:07:00.920731] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2012-04-16 14:07:00.920754] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x6x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 3) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:00.920773] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 380
[2012-04-16 14:07:00.920818] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 404, payload: 380, rpc hdr: 24
[2012-04-16 14:07:00.920850] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x5x, Program: GlusterFS 3.2.5, ProgVers: 310, Proc: 27) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:04.151099] T [rpc-clnt.c:679:rpc_clnt_handle_cbk] 0-glusterfs: received rpc message (XID: 0x2a, Ver: 2, Program: 52743234, ProgVers: 1, Proc: 1) from rpc-transport (glusterfs)
[2012-04-16 14:07:04.151165] I [glusterfsd-mgmt.c:62:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2012-04-16 14:07:04.151188] T [rpc-clnt.c:1224:rpc_clnt_record] 0-glusterfs: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:04.151207] T [rpc-clnt.c:1125:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 164, payload: 36, rpc hdr: 128
[2012-04-16 14:07:04.151244] T [rpc-clnt.c:1429:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x4x Program: GlusterFS Handshake, ProgVers: 1, Proc: 2) to rpc-transport (glusterfs)
[2012-04-16 14:07:04.158962] D [socket.c:193:__socket_rwv] 0-tcp.athena-server: EOF from peer 10.82.211.18:1017
[2012-04-16 14:07:04.159006] W [socket.c:1494:__socket_proto_state_machine] 0-tcp.athena-server: reading from socket failed. Error (Transport endpoint is not connected), peer (10.82.211.18:1017)
[2012-04-16 14:07:04.159022] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:07:04.159096] I [server.c:438:server_rpc_notify] 0-athena-server: disconnected connection from 10.82.211.18:1017
[2012-04-16 14:07:04.159124] I [server-helpers.c:783:server_connection_destroy] 0-athena-server: destroyed connection of ylal3030-3683-2012/04/16-14:06:56:829254-athena-client-1
[2012-04-16 14:07:04.159140] T [socket.c:2657:fini] 0-tcp.athena-server: transport 0x2aaaace755c0 destroyed
[2012-04-16 14:07:05.170286] T [rpc-clnt.c:638:rpc_clnt_reply_init] 0-glusterfs: received rpc message (RPC XID: 0x4x Program: GlusterFS Handshake, ProgVers: 1, Proc: 2) from rpc-transport (glusterfs)
[2012-04-16 14:07:05.170340] I [glusterfsd-mgmt.c:637:mgmt_getspec_cbk] 0-: No change in volfile, continuing
[2012-04-16 14:07:05.180518] D [socket.c:193:__socket_rwv] 0-tcp.athena-server: EOF from peer 10.80.48.26:1017
[2012-04-16 14:07:05.180548] W [socket.c:1494:__socket_proto_state_machine] 0-tcp.athena-server: reading from socket failed. Error (Transport endpoint is not connected), peer (10.80.48.26:1017)
[2012-04-16 14:07:05.180563] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:07:05.180609] I [server.c:438:server_rpc_notify] 0-athena-server: disconnected connection from 10.80.48.26:1017
[2012-04-16 14:07:05.180634] I [server-helpers.c:783:server_connection_destroy] 0-athena-server: destroyed connection of ylal3020-2452-2012/04/16-14:06:57:854053-athena-client-1
[2012-04-16 14:07:05.180650] T [socket.c:2657:fini] 0-tcp.athena-server: transport 0x2aaaacd38720 destroyed
[2012-04-16 14:07:09.215632] T [socket.c:379:__socket_nodelay] 0-: NODELAY enabled for socket 13
[2012-04-16 14:07:09.215938] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1007
[2012-04-16 14:07:09.215963] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:09.215978] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x3, Ver: 2, Program: 123451501, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.215995] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:09.216011] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GF-DUMP - DUMP
[2012-04-16 14:07:09.216031] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 136
[2012-04-16 14:07:09.216048] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 160, payload: 136, rpc hdr: 24
[2012-04-16 14:07:09.216078] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x3x, Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.216389] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1007
[2012-04-16 14:07:09.216411] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:09.216450] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x4, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.216468] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:09.216483] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - SETVOLUME
[2012-04-16 14:07:09.216541] D [addr.c:211:gf_auth] 0-/users/export: allowed = "*", received addr = "10.82.211.18"
[2012-04-16 14:07:09.216563] I [server-handshake.c:542:server_setvolume] 0-athena-server: accepted client from 10.82.211.18:1007 (version: 3.2.5)
[2012-04-16 14:07:09.216587] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 140
[2012-04-16 14:07:09.216602] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 164, payload: 140, rpc hdr: 24
[2012-04-16 14:07:09.216631] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x4x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.222882] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1007
[2012-04-16 14:07:09.222907] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:09.222921] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x5, Ver: 2, Program: 1298437, ProgVers: 310, Proc: 27) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.222948] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 1, uid: 0, gid: 0, owner: 1
[2012-04-16 14:07:09.222963] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 3.2.5 - LOOKUP
[2012-04-16 14:07:09.222997] T [server-resolve.c:127:resolve_loc_touchup] 0-athena-server: return value inode_path 1
[2012-04-16 14:07:09.223047] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1007
[2012-04-16 14:07:09.223066] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:09.223089] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x6, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 3) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.223107] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:09.223123] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - PING
[2012-04-16 14:07:09.223139] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2012-04-16 14:07:09.223153] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2012-04-16 14:07:09.223165] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 380
[2012-04-16 14:07:09.223205] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 404, payload: 380, rpc hdr: 24
[2012-04-16 14:07:09.223246] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x5x, Program: GlusterFS 3.2.5, ProgVers: 310, Proc: 27) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:09.223176] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x6x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 3) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.261681] T [socket.c:379:__socket_nodelay] 0-: NODELAY enabled for socket 15
[2012-04-16 14:07:10.261740] T [socket.c:433:__socket_keepalive] 0-: Keep-alive enabled for socket 15, interval 2, idle: 20
[2012-04-16 14:07:10.261819] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1013
[2012-04-16 14:07:10.261843] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:10.261857] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x3, Ver: 2, Program: 123451501, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.261905] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:10.261923] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GF-DUMP - DUMP
[2012-04-16 14:07:10.261943] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 136
[2012-04-16 14:07:10.261959] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 160, payload: 136, rpc hdr: 24
[2012-04-16 14:07:10.261986] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x3x, Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.262387] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1013
[2012-04-16 14:07:10.262407] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:10.262420] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x4, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.262437] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:10.262451] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - SETVOLUME
[2012-04-16 14:07:10.262505] D [addr.c:211:gf_auth] 0-/users/export: allowed = "*", received addr = "10.80.48.26"
[2012-04-16 14:07:10.262525] I [server-handshake.c:542:server_setvolume] 0-athena-server: accepted client from 10.80.48.26:1013 (version: 3.2.5)
[2012-04-16 14:07:10.262549] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 140
[2012-04-16 14:07:10.262564] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 164, payload: 140, rpc hdr: 24
[2012-04-16 14:07:10.262586] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x4x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.263173] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1013
[2012-04-16 14:07:10.263194] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:10.263213] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x5, Ver: 2, Program: 1298437, ProgVers: 310, Proc: 27) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.263229] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 1, uid: 0, gid: 0, owner: 1
[2012-04-16 14:07:10.263243] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS 3.2.5 - LOOKUP
[2012-04-16 14:07:10.263276] T [server-resolve.c:127:resolve_loc_touchup] 0-athena-server: return value inode_path 1
[2012-04-16 14:07:10.263321] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1013
[2012-04-16 14:07:10.263339] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:10.263352] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x6, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 3) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.263368] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:10.263382] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GlusterFS Handshake - PING
[2012-04-16 14:07:10.263397] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2012-04-16 14:07:10.263416] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2012-04-16 14:07:10.263438] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x6x, Program: GlusterFS Handshake, ProgVers: 1, Proc: 3) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:10.263501] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 380
[2012-04-16 14:07:10.263556] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 404, payload: 380, rpc hdr: 24
[2012-04-16 14:07:48.360678] T [rpc-clnt.c:679:rpc_clnt_handle_cbk] 0-glusterfs: received rpc message (XID: 0x2a, Ver: 2, Program: 52743234, ProgVers: 1, Proc: 1) from rpc-transport (glusterfs)
[2012-04-16 14:07:48.360727] I [glusterfsd-mgmt.c:62:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2012-04-16 14:07:48.360749] T [rpc-clnt.c:1224:rpc_clnt_record] 0-glusterfs: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:48.360766] T [rpc-clnt.c:1125:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 164, payload: 36, rpc hdr: 128
[2012-04-16 14:07:48.360802] T [rpc-clnt.c:1429:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x5x Program: GlusterFS Handshake, ProgVers: 1, Proc: 2) to rpc-transport (glusterfs)
[2012-04-16 14:07:48.367378] D [socket.c:193:__socket_rwv] 0-tcp.athena-server: EOF from peer 10.82.211.18:1007
[2012-04-16 14:07:48.367411] W [socket.c:1494:__socket_proto_state_machine] 0-tcp.athena-server: reading from socket failed. Error (Transport endpoint is not connected), peer (10.82.211.18:1007)
[2012-04-16 14:07:48.367427] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:07:48.367507] I [server.c:438:server_rpc_notify] 0-athena-server: disconnected connection from 10.82.211.18:1007
[2012-04-16 14:07:48.367536] I [server-helpers.c:783:server_connection_destroy] 0-athena-server: destroyed connection of ylal3030-3701-2012/04/16-14:07:05:166119-athena-client-1
[2012-04-16 14:07:48.367552] T [socket.c:2657:fini] 0-tcp.athena-server: transport 0x2aaaacd38720 destroyed
[2012-04-16 14:07:49.381689] T [rpc-clnt.c:638:rpc_clnt_reply_init] 0-glusterfs: received rpc message (RPC XID: 0x5x Program: GlusterFS Handshake, ProgVers: 1, Proc: 2) from rpc-transport (glusterfs)
[2012-04-16 14:07:49.381744] I [glusterfsd-mgmt.c:637:mgmt_getspec_cbk] 0-: No change in volfile, continuing
[2012-04-16 14:07:49.391581] D [socket.c:193:__socket_rwv] 0-tcp.athena-server: EOF from peer 10.80.48.26:1013
[2012-04-16 14:07:49.391622] W [socket.c:1494:__socket_proto_state_machine] 0-tcp.athena-server: reading from socket failed. Error (Transport endpoint is not connected), peer (10.80.48.26:1013)
[2012-04-16 14:07:49.391643] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
[2012-04-16 14:07:49.391693] I [server.c:438:server_rpc_notify] 0-athena-server: disconnected connection from 10.80.48.26:1013
[2012-04-16 14:07:49.391718] I [server-helpers.c:783:server_connection_destroy] 0-athena-server: destroyed connection of ylal3020-2460-2012/04/16-14:07:06:190820-athena-client-1
[2012-04-16 14:07:49.391735] T [socket.c:2657:fini] 0-tcp.athena-server: transport 0x2aaaacd02aa0 destroyed
[2012-04-16 14:07:53.435449] T [socket.c:379:__socket_nodelay] 0-: NODELAY enabled for socket 13
[2012-04-16 14:07:53.435507] T [socket.c:433:__socket_keepalive] 0-: Keep-alive enabled for socket 13, interval 2, idle: 20
[2012-04-16 14:07:53.437716] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1022
[2012-04-16 14:07:53.437758] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:53.437780] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x3, Ver: 2, Program: 123451501, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:53.437798] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
[2012-04-16 14:07:53.437814] T [rpcsvc.c:187:rpcsvc_program_actor] 0-rpc-service: Actor found: GF-DUMP - DUMP
[2012-04-16 14:07:53.437834] T [rpcsvc.c:1003:rpcsvc_submit_generic] 0-rpc-service: Tx message: 136
[2012-04-16 14:07:53.437884] T [rpcsvc.c:640:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 160, payload: 136, rpc hdr: 24
[2012-04-16 14:07:53.437925] T [rpcsvc.c:1040:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x3x, Program: GF-DUMP, ProgVers: 1, Proc: 1) to rpc-transport (tcp.athena-server)
[2012-04-16 14:07:53.440215] T [rpcsvc.c:443:rpcsvc_handle_rpc_call] 0-rpcsvc: Client port: 1022
[2012-04-16 14:07:53.440251] T [rpcsvc-auth.c:302:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS
[2012-04-16 14:07:53.440272] T [rpcsvc.c:356:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x4, Ver: 2, Program: 14398633, ProgVers: 1, Proc: 1) from rpc-transport (tcp.athena-server)
[2012-04-16 14:07:53.440290] T [auth-glusterfs.c:191:auth_glusterfs_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 0
Comment 1 Anthony 2012-07-18 09:47:28 UTC 
Same Bug in 3.3.0 : 

# mount -o proto=tcp,vers=3 nfs://yval1010:/test /users/glusterfs_mnt 
=> OK

# mount -o proto=tcp,vers=3 nfs://yval1010:/test/test2 /users/glusterfs_mnt
nfs mount: yval1010: : RPC: Program not registered
nfs mount: retrying: /users/glusterfs_mnt


nfs.log : 

[2012-07-18 11:43:43.484994] E [nfs3.c:305:__nfs3_get_volume_id] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup+0x125) [0x7f5418ea4e15] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup_reply+0x48) [0x7f5418e9b908] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_request_xlator_deviceid+0x4c) [0x7f5418e9a54c]))) 0-nfs-nfsv3: invalid argument: xl
[2012-07-18 11:43:43.491088] E [nfs3.c:305:__nfs3_get_volume_id] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup+0x125) [0x7f5418ea4e15] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup_reply+0x48) [0x7f5418e9b908] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_request_xlator_deviceid+0x4c) [0x7f5418e9a54c]))) 0-nfs-nfsv3: invalid argument: xl
[2012-07-18 11:43:48.494268] E [nfs3.c:305:__nfs3_get_volume_id] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup+0x125) [0x7f5418ea4e15] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup_reply+0x48) [0x7f5418e9b908] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_request_xlator_deviceid+0x4c) [0x7f5418e9a54c]))) 0-nfs-nfsv3: invalid argument: xl
[2012-07-18 11:43:48.992370] W [socket.c:195:__socket_rwv] 0-socket.nfs-server: readv failed (Connection reset by peer)
[2012-07-18 11:43:57.422070] W [socket.c:195:__socket_rwv] 0-socket.nfs-server: readv failed (Connection reset by peer)
[2012-07-18 11:43:58.498666] E [nfs3.c:305:__nfs3_get_volume_id] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup+0x125) [0x7f5418ea4e15] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_lookup_reply+0x48) [0x7f5418e9b908] (-->/usr/local/lib//glusterfs/3.3.0/xlator/nfs/server.so(nfs3_request_xlator_deviceid+0x4c) [0x7f5418e9a54c]))) 0-nfs-nfsv3: invalid argument: xl
Comment 2 Anthony 2012-07-23 07:26:36 UTC 
fwding from krishna's mail, need to update the docs with this info:
 
Here are the steps:
on linux client machine:
* make sure you have the directory you want to export is already created, if 
not create it.
  if /mnt/nfs is the mount point do this:
  mkdir /mnt/nfs/subdir
* on storage node do:
  gluster volume set <volname> nfs.export-dir /subdir
  gluster volume set <volname> nfs.mount-udp on
* do a "showmount -e <storage-node-ip>" to see that subdir is exported too.
* on a LINUX client do this:
  mount -o proto=tcp <storage-node-ip>:/<volname>/subdir /mnt/nfs
  i.e you are mounting the subdir.
* now on SOLARIS client do this:
  mount nfs://<storage-node-ip>:/<volname>/subdir /mnt/nfs
  you should be able to access the exported subdir on Solaris machine. note 
that you have to mount the subdir on a linux machine first with proto=tcp 
before trying to mount on solaris machine.
Note You need to log in before you can comment on or make changes to this bug.