Attachment 585126 Details for Bug 822361 – nfs server log

nfs server log

nfs.log (text/x-log), 29.28 KB, created by Shwetha Panduranga on 2012-05-17 07:20:53 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Shwetha Panduranga

Created: 2012-05-17 07:20:53 UTC

Size: 29.28 KB

patch

obsolete

>[2012-05-17 15:54:22.794847] I [glusterfsd.c:1651:main] 0-/usr/local/sbin/glusterfs: Started running /usr/local/sbin/glusterfs version 3.3.0qa41
>[2012-05-17 15:54:22.949419] I [nfs.c:802:init] 0-nfs: NFS service started
>[2012-05-17 15:54:22.951949] D [client.c:2315:client_init_grace_timer] 0-dstore-client-1: lk-heal = off
>[2012-05-17 15:54:22.952008] D [client.c:2326:client_init_grace_timer] 0-dstore-client-1: Client grace timeout value = 10
>[2012-05-17 15:54:22.952053] D [options.c:1044:xlator_option_init_path] 0-dstore-client-1: option remote-subvolume using set value /export_sdb/brick1
>[2012-05-17 15:54:22.953074] D [rpc-clnt.c:973:rpc_clnt_connection_init] 0-dstore-client-1: defaulting frame-timeout to 30mins
>[2012-05-17 15:54:22.953132] D [rpc-transport.c:248:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/local/lib/glusterfs/3.3.0qa41/rpc-transport/socket.so
>[2012-05-17 15:54:22.953236] D [rpc-clnt.c:1379:rpcclnt_cbk_program_register] 0-dstore-client-1: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2012-05-17 15:54:22.953269] D [client.c:2290:client_init_rpc] 0-dstore-client-1: client init successful
>[2012-05-17 15:54:22.953299] D [client.c:2315:client_init_grace_timer] 0-dstore-client-0: lk-heal = off
>[2012-05-17 15:54:22.953320] D [client.c:2326:client_init_grace_timer] 0-dstore-client-0: Client grace timeout value = 10
>[2012-05-17 15:54:22.953346] D [options.c:1044:xlator_option_init_path] 0-dstore-client-0: option remote-subvolume using set value /export_sdb/brick0
>[2012-05-17 15:54:22.954663] D [rpc-clnt.c:973:rpc_clnt_connection_init] 0-dstore-client-0: defaulting frame-timeout to 30mins
>[2012-05-17 15:54:22.954717] D [rpc-transport.c:248:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/local/lib/glusterfs/3.3.0qa41/rpc-transport/socket.so
>[2012-05-17 15:54:22.954775] D [rpc-clnt.c:1379:rpcclnt_cbk_program_register] 0-dstore-client-0: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2012-05-17 15:54:22.954801] D [client.c:2290:client_init_rpc] 0-dstore-client-0: client init successful
>[2012-05-17 15:54:22.954837] W [graph.c:316:_log_if_unknown_option] 0-nfs-server: option 'rpc-auth.auth-glusterfs' is not recognized
>[2012-05-17 15:54:22.954870] W [graph.c:316:_log_if_unknown_option] 0-nfs-server: option 'rpc-auth-allow-insecure' is not recognized
>[2012-05-17 15:54:22.954898] W [graph.c:316:_log_if_unknown_option] 0-nfs-server: option 'transport-type' is not recognized
>[2012-05-17 15:54:22.954953] I [client.c:2142:notify] 0-dstore-client-0: parent translators are ready, attempting connect on transport
>[2012-05-17 15:54:22.954983] D [name.c:149:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-05-17 15:54:22.961483] D [common-utils.c:151:gf_resolve_ip6] 0-resolver: returning ip-192.168.2.35 (port-24007) for hostname: 192.168.2.35 and port: 24007
>[2012-05-17 15:54:22.961793] I [client.c:2142:notify] 0-dstore-client-1: parent translators are ready, attempting connect on transport
>[2012-05-17 15:54:22.961834] D [name.c:149:client_fill_address_family] 0-dstore-client-1: address-family not specified, guessing it to be inet/inet6
>[2012-05-17 15:54:22.968323] D [common-utils.c:151:gf_resolve_ip6] 0-resolver: returning ip-192.168.2.36 (port-24007) for hostname: 192.168.2.36 and port: 24007
>Given volfile:
>+------------------------------------------------------------------------------+
>  1: volume dstore-client-0
>  2:     type protocol/client
>  3:     option remote-host 192.168.2.35
>  4:     option remote-subvolume /export_sdb/brick0
>  5:     option transport-type tcp
>  6:     option username ef436ee7-d4eb-480e-8879-0e0c70c7e602
>  7:     option password 637a8727-4401-4f63-8c3a-d7cea0e08e92
>  8: end-volume
>  9: 
> 10: volume dstore-client-1
> 11:     type protocol/client
> 12:     option remote-host 192.168.2.36
> 13:     option remote-subvolume /export_sdb/brick1
> 14:     option transport-type tcp
> 15:     option username ef436ee7-d4eb-480e-8879-0e0c70c7e602
> 16:     option password 637a8727-4401-4f63-8c3a-d7cea0e08e92
> 17: end-volume
> 18: 
> 19: volume dstore-replicate-0
> 20:     type cluster/replicate
> 21:     subvolumes dstore-client-0 dstore-client-1
> 22: end-volume
> 23: 
> 24: volume dstore
> 25:     type debug/io-stats
> 26:     option log-level DEBUG
> 27:     option latency-measurement off
> 28:     option count-fop-hits off
> 29:     subvolumes dstore-replicate-0
> 30: end-volume
> 31: 
> 32: volume nfs-server
> 33:     type nfs/server
> 34:     option nfs.dynamic-volumes on
> 35:     option nfs.nlm on
> 36:     option rpc-auth.addr.dstore.allow *
> 37:     option nfs3.dstore.volume-id 60f49687-483d-4150-967e-f9835d4d08c9
> 38:     subvolumes dstore
> 39: end-volume
>
>+------------------------------------------------------------------------------+
>[2012-05-17 15:54:22.968712] D [glusterfsd-mgmt.c:2050:glusterfs_mgmt_pmap_signin] 0-fsd-mgmt: portmapper signin arguments not given
>[2012-05-17 15:54:22.968798] D [client.c:2043:client_rpc_notify] 0-dstore-client-0: got RPC_CLNT_CONNECT
>[2012-05-17 15:54:22.969010] D [client-handshake.c:184:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:22.969071] D [client.c:2043:client_rpc_notify] 0-dstore-client-1: got RPC_CLNT_CONNECT
>[2012-05-17 15:54:22.969142] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:22.969248] D [client-handshake.c:1662:server_has_portmap] 0-dstore-client-0: detected portmapper on server
>[2012-05-17 15:54:22.969404] D [client-handshake.c:184:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:22.969469] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-dstore-client-0: changing port to 24009 (from 0)
>[2012-05-17 15:54:22.969597] D [socket.c:184:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24007
>[2012-05-17 15:54:22.969640] D [socket.c:1512:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24007)
>[2012-05-17 15:54:22.969662] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now
>[2012-05-17 15:54:22.969699] D [client.c:2108:client_rpc_notify] 0-dstore-client-0: disconnected (skipped notify)
>[2012-05-17 15:54:23.190096] D [client-handshake.c:1662:server_has_portmap] 0-dstore-client-1: detected portmapper on server
>[2012-05-17 15:54:23.190194] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:23.190569] E [client-handshake.c:1709:client_query_portmap_cbk] 0-dstore-client-1: failed to get the port number for remote subvolume
>[2012-05-17 15:54:23.190641] D [socket.c:184:__socket_rwv] 0-dstore-client-1: EOF from peer 192.168.2.36:24007
>[2012-05-17 15:54:23.190672] D [socket.c:1512:__socket_proto_state_machine] 0-dstore-client-1: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.36:24007)
>[2012-05-17 15:54:23.190692] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now
>[2012-05-17 15:54:23.190730] I [client.c:2090:client_rpc_notify] 0-dstore-client-1: disconnected
>[2012-05-17 15:54:26.085963] W [socket.c:410:__socket_keepalive] 0-socket: failed to set keep idle on socket 8
>[2012-05-17 15:54:26.086014] W [socket.c:1876:socket_server_event_handler] 0-socket.glusterfsd: Failed to set keep-alive: Operation not supported
>[2012-05-17 15:54:26.821348] D [name.c:149:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-05-17 15:54:26.828097] D [common-utils.c:151:gf_resolve_ip6] 0-resolver: returning ip-192.168.2.35 (port-24007) for hostname: 192.168.2.35 and port: 24007
>[2012-05-17 15:54:26.828429] D [name.c:149:client_fill_address_family] 0-dstore-client-1: address-family not specified, guessing it to be inet/inet6
>[2012-05-17 15:54:26.828477] D [client.c:2043:client_rpc_notify] 0-dstore-client-0: got RPC_CLNT_CONNECT
>[2012-05-17 15:54:26.828628] D [client-handshake.c:184:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:26.828825] I [client-handshake.c:1628:select_server_supported_programs] 0-dstore-client-0: Using Program GlusterFS 3.3.0qa41, Num (1298437), Version (330)
>[2012-05-17 15:54:26.829002] D [client-handshake.c:184:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:26.837162] D [client-handshake.c:1399:client_setvolume_cbk] 0-dstore-client-0: clnt-lk-version = 1, server-lk-version = 0
>[2012-05-17 15:54:26.837208] I [client-handshake.c:1425:client_setvolume_cbk] 0-dstore-client-0: Connected to 192.168.2.35:24009, attached to remote volume '/export_sdb/brick0'.
>[2012-05-17 15:54:26.837230] I [client-handshake.c:1437:client_setvolume_cbk] 0-dstore-client-0: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-17 15:54:26.837249] D [client-handshake.c:1287:client_post_handshake] 0-dstore-client-0: No fds to open - notifying all parents child up
>[2012-05-17 15:54:26.837273] D [client-handshake.c:477:client_set_lk_version] 0-dstore-client-0: Sending SET_LK_VERSION
>[2012-05-17 15:54:26.837370] I [afr-common.c:3620:afr_notify] 0-dstore-replicate-0: Subvolume 'dstore-client-0' came back up; going online.
>[2012-05-17 15:54:26.837784] I [client-handshake.c:453:client_set_lk_version_cbk] 0-dstore-client-0: Server lk version = 1
>[2012-05-17 15:54:26.838502] I [afr-common.c:1962:afr_set_root_inode_on_first_lookup] 0-dstore-replicate-0: added root inode
>[2012-05-17 15:54:26.838582] D [afr-self-heal-common.c:139:afr_sh_print_pending_matrix] 0-dstore-replicate-0: pending_matrix: [ 0 0 ]
>[2012-05-17 15:54:26.838614] D [afr-self-heal-common.c:139:afr_sh_print_pending_matrix] 0-dstore-replicate-0: pending_matrix: [ 0 0 ]
>[2012-05-17 15:54:26.838638] D [afr-self-heal-common.c:744:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-05-17 15:54:26.838662] D [afr-self-heal-data.c:833:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 0
>[2012-05-17 15:54:26.838683] D [afr-common.c:1292:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 0 for /
>[2012-05-17 15:54:26.838711] D [afr-common.c:1094:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 0
>[2012-05-17 15:54:26.838734] D [afr-common.c:1633:afr_lookup_perform_self_heal] 0-dstore-replicate-0: Only 1 child up - do not attempt to detect self heal
>[2012-05-17 15:54:26.838759] D [nfs.c:239:nfs_subvolume_set_started] 0-nfs: Starting up: dstore , vols started till now: 1
>[2012-05-17 15:54:26.840559] D [common-utils.c:151:gf_resolve_ip6] 0-resolver: returning ip-192.168.2.36 (port-24007) for hostname: 192.168.2.36 and port: 24007
>[2012-05-17 15:54:26.840805] D [client.c:2043:client_rpc_notify] 0-dstore-client-1: got RPC_CLNT_CONNECT
>[2012-05-17 15:54:26.840883] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:26.841084] D [client-handshake.c:1662:server_has_portmap] 0-dstore-client-1: detected portmapper on server
>[2012-05-17 15:54:26.841169] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:26.841311] I [rpc-clnt.c:1660:rpc_clnt_reconfig] 0-dstore-client-1: changing port to 24009 (from 0)
>[2012-05-17 15:54:26.841392] D [socket.c:184:__socket_rwv] 0-dstore-client-1: EOF from peer 192.168.2.36:24007
>[2012-05-17 15:54:26.841425] D [socket.c:1512:__socket_proto_state_machine] 0-dstore-client-1: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.36:24007)
>[2012-05-17 15:54:26.841445] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now
>[2012-05-17 15:54:26.841533] D [client.c:2108:client_rpc_notify] 0-dstore-client-1: disconnected (skipped notify)
>[2012-05-17 15:54:30.841170] D [name.c:149:client_fill_address_family] 0-dstore-client-1: address-family not specified, guessing it to be inet/inet6
>[2012-05-17 15:54:30.847736] D [common-utils.c:151:gf_resolve_ip6] 0-resolver: returning ip-192.168.2.36 (port-24007) for hostname: 192.168.2.36 and port: 24007
>[2012-05-17 15:54:30.848061] D [client.c:2043:client_rpc_notify] 0-dstore-client-1: got RPC_CLNT_CONNECT
>[2012-05-17 15:54:30.848205] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:30.848428] I [client-handshake.c:1628:select_server_supported_programs] 0-dstore-client-1: Using Program GlusterFS 3.3.0qa41, Num (1298437), Version (330)
>[2012-05-17 15:54:30.848534] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-05-17 15:54:30.848912] D [client-handshake.c:1399:client_setvolume_cbk] 0-dstore-client-1: clnt-lk-version = 1, server-lk-version = 0
>[2012-05-17 15:54:30.848981] I [client-handshake.c:1425:client_setvolume_cbk] 0-dstore-client-1: Connected to 192.168.2.36:24009, attached to remote volume '/export_sdb/brick1'.
>[2012-05-17 15:54:30.849002] I [client-handshake.c:1437:client_setvolume_cbk] 0-dstore-client-1: Server and Client lk-version numbers are not same, reopening the fds
>[2012-05-17 15:54:30.849020] D [client-handshake.c:1287:client_post_handshake] 0-dstore-client-1: No fds to open - notifying all parents child up
>[2012-05-17 15:54:30.849037] D [client-handshake.c:477:client_set_lk_version] 0-dstore-client-1: Sending SET_LK_VERSION
>[2012-05-17 15:54:30.849304] I [client-handshake.c:453:client_set_lk_version_cbk] 0-dstore-client-1: Server lk version = 1
>[2012-05-17 15:55:08.852874] D [client-handshake.c:184:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-05-17 15:55:12.853546] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-05-17 15:55:23.449697] D [socket.c:184:__socket_rwv] 0-socket.nfs-server: EOF from peer 192.168.2.1:56403
>[2012-05-17 15:55:23.449773] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now
>[2012-05-17 15:55:23.459145] D [socket.c:184:__socket_rwv] 0-socket.nfs-server: EOF from peer 192.168.2.1:37657
>[2012-05-17 15:55:23.459187] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now
>[2012-05-17 15:55:23.463448] D [mount3.c:909:mnt3svc_mnt] 0-nfs-mount: dirpath: /dstore
>[2012-05-17 15:55:23.463495] D [mount3.c:852:mnt3_find_export] 0-nfs-mount: dirpath: /dstore
>[2012-05-17 15:55:23.463523] D [mount3.c:746:mnt3_mntpath_to_export] 0-nfs-mount: Found export volume: dstore
>[2012-05-17 15:55:23.464509] D [afr-self-heal-common.c:139:afr_sh_print_pending_matrix] 0-dstore-replicate-0: pending_matrix: [ 0 0 ]
>[2012-05-17 15:55:23.464550] D [afr-self-heal-common.c:139:afr_sh_print_pending_matrix] 0-dstore-replicate-0: pending_matrix: [ 0 0 ]
>[2012-05-17 15:55:23.464571] D [afr-self-heal-common.c:744:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-05-17 15:55:23.464592] D [afr-self-heal-data.c:833:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 0
>[2012-05-17 15:55:23.464610] D [afr-common.c:1292:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 0 for /
>[2012-05-17 15:55:23.464633] D [afr-common.c:1094:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 0
>[2012-05-17 15:55:23.464684] D [mount3.c:305:mnt3svc_lookup_mount_cbk] 0-nfs-mount: MNT reply: fh FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001, status: 0
>[2012-05-17 15:55:23.466311] D [socket.c:184:__socket_rwv] 0-socket.nfs-server: EOF from peer 192.168.2.1:949
>[2012-05-17 15:55:23.466357] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now
>[2012-05-17 15:55:23.471181] D [rpcsvc.c:1113:rpcsvc_error_reply] (-->/usr/local/lib/libgfrpc.so.0(rpc_transport_notify+0x130) [0x7f2dc09b9ec8] (-->/usr/local/lib/libgfrpc.so.0(rpcsvc_notify+0x181) [0x7f2dc09b4463] (-->/usr/local/lib/libgfrpc.so.0(rpcsvc_handle_rpc_call+0x37b) [0x7f2dc09b40c6]))) 0-: sending a RPC error reply
>[2012-05-17 15:55:23.472435] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6322b80b, FSINFO: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.473241] D [afr-self-heal-common.c:139:afr_sh_print_pending_matrix] 0-dstore-replicate-0: pending_matrix: [ 0 0 ]
>[2012-05-17 15:55:23.473281] D [afr-self-heal-common.c:139:afr_sh_print_pending_matrix] 0-dstore-replicate-0: pending_matrix: [ 0 0 ]
>[2012-05-17 15:55:23.473301] D [afr-self-heal-common.c:744:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-05-17 15:55:23.473320] D [afr-self-heal-data.c:833:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 0
>[2012-05-17 15:55:23.473338] D [afr-common.c:1292:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 0 for /
>[2012-05-17 15:55:23.473359] D [afr-common.c:1094:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 0
>[2012-05-17 15:55:23.473434] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.473856] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6322b80b, FSINFO: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.476582] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6422b80b, PATHCONF: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.476640] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.476958] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6422b80b, PATHCONF: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.478822] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6522b80b, FSINFO: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.478877] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.479195] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6522b80b, FSINFO: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.550530] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6622b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.550600] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.550911] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6622b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.552510] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6722b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.552589] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.552956] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6722b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 7(Argument list too long)
>[2012-05-17 15:55:23.554665] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6822b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.554725] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.555016] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6822b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 7(Argument list too long)
>[2012-05-17 15:55:23.556295] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6922b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.556351] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.556629] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6922b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.560750] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6a22b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.560806] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.561074] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6a22b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 7(Argument list too long)
>[2012-05-17 15:55:23.562370] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6b22b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.562423] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.562707] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6b22b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.564367] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6c22b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.564420] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.564811] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6c22b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 7(Argument list too long)
>[2012-05-17 15:55:23.567125] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6d22b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.567179] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.567496] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6d22b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.569134] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 6e22b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.569195] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.569485] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 6e22b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.571028] D [nfs3-helpers.c:3523:nfs3_log_readdir_call] 0-nfs-nfsv3: XID: 6f22b80b, READDIRPLUS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001, dircount: 4096, maxcount: 32768
>[2012-05-17 15:55:23.571117] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.571716] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.572098] D [nfs3-helpers.c:3489:nfs3_log_readdirp_res] 0-nfs-nfsv3: XID: 6f22b80b, READDIRPLUS: NFS: 0(Call completed successfully.), POSIX: 0(Success), dircount: 4096, maxcount: 32768, cverf: 39267836, is_eof: 1
>[2012-05-17 15:55:23.573606] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7022b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.573660] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.573888] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7022b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 7(Argument list too long)
>[2012-05-17 15:55:23.575263] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7122b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.575320] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.575585] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7122b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:23.579261] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7222b80b, GETATTR: args: FH: hashcount 1, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid fb0aa6ff-7e0b-4279-bc11-cf2d0a6a0712
>[2012-05-17 15:55:23.580048] E [nfs3.c:753:nfs3_getattr_resume] 0-nfs-nfsv3: Unable to resolve FH: (192.168.2.1:961) dstore : fb0aa6ff-7e0b-4279-bc11-cf2d0a6a0712
>[2012-05-17 15:55:23.580091] W [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7222b80b, GETATTR: NFS: 2(No such file or directory), POSIX: 14(Bad address)
>[2012-05-17 15:55:23.581654] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7322b80b, GETATTR: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:23.581710] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:23.581987] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7322b80b, GETATTR: NFS: 0(Call completed successfully.), POSIX: 0(Success)
>[2012-05-17 15:55:24.503230] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7422b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:24.503351] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:24.503766] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7422b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 5(Input/output error)
>[2012-05-17 15:55:24.505727] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7522b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:24.505799] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:24.506102] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7522b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 5(Input/output error)
>[2012-05-17 15:55:24.507507] D [nfs3-helpers.c:1641:nfs3_log_fh_entry_call] 0-nfs-nfsv3: XID: 7622b80b, LOOKUP: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001, name: .Trash
>[2012-05-17 15:55:24.508280] D [nfs3-helpers.c:3458:nfs3_log_newfh_res] 0-nfs-nfsv3: XID: 7622b80b, LOOKUP: NFS: 2(No such file or directory), POSIX: 2(No such file or directory), FH: hashcount 0, exportid 00000000-0000-0000-0000-000000000000, gfid 00000000-0000-0000-0000-000000000000
>[2012-05-17 15:55:24.509727] D [nfs3-helpers.c:1627:nfs3_log_common_call] 0-nfs-nfsv3: XID: 7722b80b, ACCESS: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001
>[2012-05-17 15:55:24.509784] D [afr-common.c:701:afr_get_call_child] 0-dstore-replicate-0: Returning 0, call_child: 0, last_index: -1
>[2012-05-17 15:55:24.510126] D [nfs3-helpers.c:3389:nfs3_log_common_res] 0-nfs-nfsv3: XID: 7722b80b, ACCESS: NFS: 0(Call completed successfully.), POSIX: 5(Input/output error)
>[2012-05-17 15:55:24.511474] D [nfs3-helpers.c:1641:nfs3_log_fh_entry_call] 0-nfs-nfsv3: XID: 7822b80b, LOOKUP: args: FH: hashcount 0, exportid 60f49687-483d-4150-967e-f9835d4d08c9, gfid 00000000-0000-0000-0000-000000000001, name: .Trash-500
>[2012-05-17 15:55:24.511985] D [nfs3-helpers.c:3458:nfs3_log_newfh_res] 0-nfs-nfsv3: XID: 7822b80b, LOOKUP: NFS: 2(No such file or directory), POSIX: 2(No such file or directory), FH: hashcount 0, exportid 00000000-0000-0000-0000-000000000000, gfid 00000000-0000-0000-0000-000000000000
>[2012-05-17 15:56:05.860662] D [client-handshake.c:184:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-05-17 15:56:05.860777] D [client-handshake.c:184:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-05-17 16:00:24.476984] D [socket.c:184:__socket_rwv] 0-socket.nfs-server: EOF from peer 192.168.2.1:961
>[2012-05-17 16:00:24.477110] D [socket.c:1798:socket_event_handler] 0-transport: disconnecting now

Actions: View

Attachments on bug 822361: 585124 | 585126