Attachment 573597 Details for Bug 807976 – fuse mount log

fuse mount log

mnt-gfsc1.log (text/x-log), 90.74 KB, created by Shwetha Panduranga on 2012-03-29 09:25:14 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Shwetha Panduranga

Created: 2012-03-29 09:25:14 UTC

Size: 90.74 KB

patch

obsolete

>[2012-03-29 17:15:47.757491] I [glusterfsd.c:1493:main] 0-/usr/local/sbin/glusterfs: Started running /usr/local/sbin/glusterfs version 3.2.6
>[2012-03-29 17:15:47.793459] I [xlator.c:1840:is_gf_log_command] 0-glusterfs: setting log level to 8 (old-value=7)
>[2012-03-29 17:15:47.793501] I [io-stats.c:2393:iostats_configure_options] 0-dstore: changing log-level to DEBUG
>[2012-03-29 17:15:47.793519] D [io-stats.c:2398:iostats_configure_options] 0-dstore: Returning 0
>[2012-03-29 17:15:47.793551] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793588] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793609] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793626] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793644] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793701] W [write-behind.c:3023:init] 0-dstore-write-behind: disabling write-behind for first 0 bytes
>[2012-03-29 17:15:47.793730] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793747] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793779] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793797] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793834] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.793853] D [client.c:1992:build_client_config] 0-dstore-client-1: defaulting remote-port to 'auto'
>[2012-03-29 17:15:47.793869] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.806279] D [rpc-clnt.c:919:rpc_clnt_connection_init] 0-dstore-client-1: defaulting frame-timeout to 30mins
>[2012-03-29 17:15:47.806344] D [rpc-transport.c:673:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/local/lib/glusterfs/3.2.6/rpc-transport/socket.so
>[2012-03-29 17:15:47.806390] D [rpc-clnt.c:1301:rpcclnt_cbk_program_register] 0-dstore-client-1: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2012-03-29 17:15:47.806472] D [client.c:2117:client_init_rpc] 0-dstore-client-1: client init successful
>[2012-03-29 17:15:47.806501] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.806520] D [client.c:1992:build_client_config] 0-dstore-client-0: defaulting remote-port to 'auto'
>[2012-03-29 17:15:47.806536] D [xlator.c:1949:xlator_get_volopt_info] 0-: Returning 0
>[2012-03-29 17:15:47.825728] D [rpc-clnt.c:919:rpc_clnt_connection_init] 0-dstore-client-0: defaulting frame-timeout to 30mins
>[2012-03-29 17:15:47.825786] D [rpc-transport.c:673:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/local/lib/glusterfs/3.2.6/rpc-transport/socket.so
>[2012-03-29 17:15:47.825989] D [rpc-clnt.c:1301:rpcclnt_cbk_program_register] 0-dstore-client-0: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2012-03-29 17:15:47.826015] D [client.c:2117:client_init_rpc] 0-dstore-client-0: client init successful
>[2012-03-29 17:15:47.826054] D [fuse-bridge.c:3357:notify] 0-fuse: got event 12 on graph 0
>[2012-03-29 17:15:47.826106] I [client.c:1935:notify] 0-dstore-client-0: parent translators are ready, attempting connect on transport
>[2012-03-29 17:15:47.826156] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:15:47.830776] 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-03-29 17:15:47.830964] I [client.c:1935:notify] 0-dstore-client-1: parent translators are ready, attempting connect on transport
>[2012-03-29 17:15:47.831005] D [name.c:157:client_fill_address_family] 0-dstore-client-1: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:15:47.835534] 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 /export1/dstore1
>  5:     option transport-type tcp
>  6: end-volume
>  7: 
>  8: volume dstore-client-1
>  9:     type protocol/client
> 10:     option remote-host 192.168.2.36
> 11:     option remote-subvolume /export1/dstore1
> 12:     option transport-type tcp
> 13: end-volume
> 14: 
> 15: volume dstore-replicate-0
> 16:     type cluster/replicate
> 17:     subvolumes dstore-client-0 dstore-client-1
> 18: end-volume
> 19: 
> 20: volume dstore-write-behind
> 21:     type performance/write-behind
> 22:     subvolumes dstore-replicate-0
> 23: end-volume
> 24: 
> 25: volume dstore-read-ahead
> 26:     type performance/read-ahead
> 27:     subvolumes dstore-write-behind
> 28: end-volume
> 29: 
> 30: volume dstore-io-cache
> 31:     type performance/io-cache
> 32:     subvolumes dstore-read-ahead
> 33: end-volume
> 34: 
> 35: volume dstore-quick-read
> 36:     type performance/quick-read
> 37:     subvolumes dstore-io-cache
> 38: end-volume
> 39: 
> 40: volume dstore-stat-prefetch
> 41:     type performance/stat-prefetch
> 42:     subvolumes dstore-quick-read
> 43: end-volume
> 44: 
> 45: volume dstore
> 46:     type debug/io-stats
> 47:     option log-level DEBUG
> 48:     option latency-measurement off
> 49:     option count-fop-hits off
> 50:     subvolumes dstore-stat-prefetch
> 51: end-volume
>
>+------------------------------------------------------------------------------+
>[2012-03-29 17:15:47.835784] D [glusterfsd-mgmt.c:1009:glusterfs_mgmt_pmap_signin] 0-fsd-mgmt: portmapper signin arguments not given
>[2012-03-29 17:15:47.835851] D [client.c:1856:client_rpc_notify] 0-dstore-client-0: got RPC_CLNT_CONNECT
>[2012-03-29 17:15:47.835928] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:47.836209] D [client-handshake.c:1124:server_has_portmap] 0-dstore-client-0: detected portmapper on server
>[2012-03-29 17:15:47.836290] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:47.836815] I [rpc-clnt.c:1536:rpc_clnt_reconfig] 0-dstore-client-0: changing port to 24009 (from 0)
>[2012-03-29 17:15:47.836943] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24007
>[2012-03-29 17:15:47.836973] D [socket.c:1494:__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-03-29 17:15:47.836992] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:15:47.837023] D [client.c:1901:client_rpc_notify] 0-dstore-client-0: disconnected (skipped notify)
>[2012-03-29 17:15:47.837052] D [client.c:1856:client_rpc_notify] 0-dstore-client-1: got RPC_CLNT_CONNECT
>[2012-03-29 17:15:47.837137] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:47.837473] D [client-handshake.c:1124:server_has_portmap] 0-dstore-client-1: detected portmapper on server
>[2012-03-29 17:15:47.837558] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:47.837747] I [rpc-clnt.c:1536:rpc_clnt_reconfig] 0-dstore-client-1: changing port to 24009 (from 0)
>[2012-03-29 17:15:47.837819] D [socket.c:193:__socket_rwv] 0-dstore-client-1: EOF from peer 192.168.2.36:24007
>[2012-03-29 17:15:47.837846] D [socket.c:1494:__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-03-29 17:15:47.837863] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:15:47.837890] D [client.c:1901:client_rpc_notify] 0-dstore-client-1: disconnected (skipped notify)
>[2012-03-29 17:15:51.789139] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:15:51.793848] 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-03-29 17:15:51.793982] D [name.c:157:client_fill_address_family] 0-dstore-client-1: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:15:51.795203] D [client.c:1856:client_rpc_notify] 0-dstore-client-0: got RPC_CLNT_CONNECT
>[2012-03-29 17:15:51.795310] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:51.795658] I [client-handshake.c:1090:select_server_supported_programs] 0-dstore-client-0: Using Program GlusterFS 3.2.6, Num (1298437), Version (310)
>[2012-03-29 17:15:51.795814] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:51.796299] I [client-handshake.c:913:client_setvolume_cbk] 0-dstore-client-0: Connected to 192.168.2.35:24009, attached to remote volume '/export1/dstore1'.
>[2012-03-29 17:15:51.796336] D [client-handshake.c:792:client_post_handshake] 0-dstore-client-0: no open fds - notifying all parents child up
>[2012-03-29 17:15:51.796378] I [afr-common.c:3141:afr_notify] 0-dstore-replicate-0: Subvolume 'dstore-client-0' came back up; going online.
>[2012-03-29 17:15:51.798680] 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-03-29 17:15:51.798956] D [client.c:1856:client_rpc_notify] 0-dstore-client-1: got RPC_CLNT_CONNECT
>[2012-03-29 17:15:51.799028] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:51.799335] I [client-handshake.c:1090:select_server_supported_programs] 0-dstore-client-1: Using Program GlusterFS 3.2.6, Num (1298437), Version (310)
>[2012-03-29 17:15:51.799416] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:15:51.799822] I [client-handshake.c:913:client_setvolume_cbk] 0-dstore-client-1: Connected to 192.168.2.36:24009, attached to remote volume '/export1/dstore1'.
>[2012-03-29 17:15:51.799856] D [client-handshake.c:792:client_post_handshake] 0-dstore-client-1: no open fds - notifying all parents child up
>[2012-03-29 17:15:51.799880] D [fuse-bridge.c:3357:notify] 0-fuse: got event 5 on graph 0
>[2012-03-29 17:15:51.835181] I [fuse-bridge.c:3339:fuse_graph_setup] 0-fuse: switched to graph 0
>[2012-03-29 17:15:51.835430] I [fuse-bridge.c:2927:fuse_init] 0-glusterfs-fuse: FUSE inited with protocol versions: glusterfs 7.13 kernel 7.13
>[2012-03-29 17:15:51.836502] I [afr-common.c:1520:afr_set_root_inode_on_first_lookup] 0-dstore-replicate-0: added root inode
>[2012-03-29 17:15:51.836654] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:15:51.836691] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:15:51.836710] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:15:51.836727] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:15:51.836748] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:15:51.836773] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:00.422586] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:00.422642] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:00.422744] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:00.422773] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:00.422790] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:00.422818] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:00.425285] D [afr-dir-read.c:134:afr_examine_dir_readdir_cbk] 0-dstore-replicate-0: /: no entries found in dstore-client-1
>[2012-03-29 17:16:00.425360] D [afr-dir-read.c:134:afr_examine_dir_readdir_cbk] 0-dstore-replicate-0: /: no entries found in dstore-client-0
>[2012-03-29 17:16:06.938507] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:06.938573] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:06.938637] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:06.938658] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:06.938680] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:06.938699] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:09.183278] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:09.183356] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:09.183380] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:09.183397] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:09.183414] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:09.183433] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:09.185205] D [afr-transaction.c:1026:afr_post_nonblocking_entrylk_cbk] 0-dstore-replicate-0: Non blocking entrylks done. Proceeding to FOP
>[2012-03-29 17:16:09.205578] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:16:09.207485] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:09.207531] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:09.207551] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:09.207568] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:09.207584] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:09.207601] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:12.89343] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:12.89420] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:12.89450] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:12.89469] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:12.89521] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:12.89546] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:12.92935] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:12.92985] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:12.93015] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:12.93043] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:12.93072] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:12.93098] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:12.93421] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test: failed to get the gfid from dict
>[2012-03-29 17:16:12.93991] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:12.94033] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:12.94065] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:12.94092] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:12.94159] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test
>[2012-03-29 17:16:12.94189] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:12.97460] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:12.97508] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:12.97529] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:12.97546] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:12.97562] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:12.97579] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:24.702542] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:24.702605] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:24.702627] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:24.702644] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:24.702660] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:24.702679] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:24.705754] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:24.705795] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:24.705815] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:24.705832] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:24.705864] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:24.705900] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:24.706147] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test: failed to get the gfid from dict
>[2012-03-29 17:16:24.706694] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:24.706729] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:24.706747] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:24.706763] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:24.706778] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test
>[2012-03-29 17:16:24.706795] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:25.375871] D [afr-dir-read.c:134:afr_examine_dir_readdir_cbk] 0-dstore-replicate-0: /test: no entries found in dstore-client-0
>[2012-03-29 17:16:25.375945] D [afr-dir-read.c:134:afr_examine_dir_readdir_cbk] 0-dstore-replicate-0: /test: no entries found in dstore-client-1
>[2012-03-29 17:16:25.377993] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:16:25.378602] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:16:27.196580] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:27.196640] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:27.196661] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:27.196677] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:27.196699] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:27.196720] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:27.199827] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:27.199866] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:27.199885] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:27.199916] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:27.199934] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:27.199951] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:27.200206] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test: failed to get the gfid from dict
>[2012-03-29 17:16:27.200920] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:27.200983] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:27.201016] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:27.201041] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:27.201070] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test
>[2012-03-29 17:16:27.201093] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:27.204442] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:16:27.204482] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:16:27.204502] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:16:27.204518] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:16:27.204550] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:16:27.204568] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:16:34.808247] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:16:34.808332] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:17:01.568478] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:01.568546] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:01.568567] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:01.568585] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:01.568601] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:17:01.568619] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:03.583808] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:03.583874] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:03.583895] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:03.583913] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:03.583929] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:17:03.583947] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:03.588580] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:03.588624] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:03.588645] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:03.588662] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:03.588679] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:17:03.588696] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:03.588974] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test: failed to get the gfid from dict
>[2012-03-29 17:17:03.589608] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:03.589660] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:03.589681] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:03.589699] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:03.589715] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test
>[2012-03-29 17:17:03.589733] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:07.5250] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:07.5310] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:07.5330] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:07.5346] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:07.5362] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:17:07.5380] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:07.8585] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:07.8623] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:07.8642] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:07.8658] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:07.8674] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:17:07.8690] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:07.8955] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test: failed to get the gfid from dict
>[2012-03-29 17:17:07.9556] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:17:07.9593] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:17:07.9612] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:17:07.9640] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:17:07.9668] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test
>[2012-03-29 17:17:07.9688] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:17:43.816947] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:17:43.817033] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:18:03.928657] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:18:03.928731] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:18:03.928756] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:18:03.928774] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:18:03.928806] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:18:03.928826] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:18:03.931774] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:18:03.931823] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:18:03.931853] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:18:03.931879] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:18:03.931904] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:18:03.931931] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:18:03.932192] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test: failed to get the gfid from dict
>[2012-03-29 17:18:03.932832] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:18:03.932868] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:18:03.932887] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:18:03.932903] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:18:03.932919] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test
>[2012-03-29 17:18:03.932936] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:18:36.366912] D [afr-transaction.c:1026:afr_post_nonblocking_entrylk_cbk] 0-dstore-replicate-0: Non blocking entrylks done. Proceeding to FOP
>[2012-03-29 17:18:36.367834] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:36.368868] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:36.370456] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:37.378112] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:37.379812] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:38.370188] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:38.371690] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:39.370711] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:39.372228] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:40.371269] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:40.372887] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:41.371787] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:41.373934] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:42.372357] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:42.373916] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:43.373040] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:43.374742] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:44.373706] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:44.375443] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:45.374228] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:45.375769] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:46.374748] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:46.376885] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:46.825090] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:18:46.825190] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:18:47.375350] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:47.376848] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:48.375995] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:48.377591] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:49.376397] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:49.377860] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:50.377008] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:50.378669] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:51.377682] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:51.379714] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:52.378162] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:52.379662] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:53.378675] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:53.380015] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:54.379259] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:54.380738] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:55.379811] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:55.381293] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:56.380678] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:56.382994] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:57.381129] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:57.382906] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:58.381633] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:58.383390] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:18:59.382319] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:18:59.383913] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:00.383013] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:00.384468] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:01.383621] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:01.387950] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:02.384106] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:02.385567] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:03.384902] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:03.386552] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:04.385348] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:04.386812] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:05.385787] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:05.387211] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:06.386273] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:06.388149] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:07.387064] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:07.388555] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:08.387564] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:08.389081] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:09.388445] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:09.390044] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:10.389009] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:10.390696] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:11.214298] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:11.214394] W [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:11.214453] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:11.214591] I [client.c:1883:client_rpc_notify] 0-dstore-client-0: disconnected
>[2012-03-29 17:19:11.214691] D [fuse-bridge.c:3357:notify] 0-fuse: got event 8 on graph 0
>[2012-03-29 17:19:11.394867] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:11.396840] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:12.390201] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:12.391442] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:13.390755] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:13.391885] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:14.391272] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:14.392458] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:15.391850] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:15.393052] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:16.392365] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:16.393726] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:17.393027] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:17.394531] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:18.393565] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:18.396671] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:19.394054] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:19.395287] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:20.394610] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:20.395869] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:21.395223] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:21.396423] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:21.829661] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:21.834561] 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-03-29 17:19:21.834848] E [socket.c:1685:socket_connect_finish] 0-dstore-client-0: connection to 192.168.2.35:24009 failed (Connection refused)
>[2012-03-29 17:19:21.834903] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:21.834939] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:21.834960] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:21.834977] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:22.211651] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:19:22.211712] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:19:22.211733] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:19:22.211760] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:19:22.211781] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:19:22.211800] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:19:22.211818] D [afr-common.c:1297:afr_lookup_perform_self_heal_if_needed] 0-dstore-replicate-0: Only 1 child up - do not attempt to detect self heal
>[2012-03-29 17:19:22.395911] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:22.397889] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:23.396479] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:23.397835] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:24.397044] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:24.398422] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:24.835083] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:24.839884] 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-03-29 17:19:24.840216] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:24.840309] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:24.840339] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:24.840365] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:25.397632] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:25.398931] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:26.398053] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:26.399501] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:27.398894] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:27.400644] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:27.840452] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:27.845450] 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-03-29 17:19:27.845728] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:27.845809] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:27.845853] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:27.845878] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:28.399396] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:28.400766] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:29.400049] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:29.401289] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:29.845839] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 1)
>[2012-03-29 17:19:29.845950] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:19:30.400551] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:30.401787] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:30.846118] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:30.850946] 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-03-29 17:19:30.851216] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:30.851308] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:30.851342] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:30.851364] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:31.401140] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:31.402786] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:32.401723] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:32.403641] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:33.402390] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:33.403800] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:33.851536] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:33.856381] 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-03-29 17:19:33.856661] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:33.856753] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:33.856796] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:33.856821] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:34.402897] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:34.404228] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:35.403376] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:35.404715] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:36.403970] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:36.405339] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:36.856947] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:36.861899] 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-03-29 17:19:36.862188] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:36.862281] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:36.862320] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:36.862358] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:37.404558] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:37.405965] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:38.405136] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:38.406601] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:39.405785] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:39.407133] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:39.862447] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:39.867457] 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-03-29 17:19:39.867710] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:39.867786] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:39.867816] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:39.867837] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:40.406436] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:40.407708] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:41.407063] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:41.408399] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:42.407579] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:42.409043] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:42.868007] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:42.872804] 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-03-29 17:19:42.873183] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:42.873274] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:42.873308] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:42.873331] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:43.408155] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:43.409355] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:44.408738] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:44.410061] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:45.409182] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:45.410434] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:45.873458] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:45.878416] 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-03-29 17:19:45.878714] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:45.878787] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:45.878829] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:45.878854] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:46.409833] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:46.411253] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:47.410447] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:47.411822] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:48.410997] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:48.412305] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:48.878981] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:48.883740] 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-03-29 17:19:48.884021] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:48.884094] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:48.884160] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:48.884185] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:49.411518] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:49.413182] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:50.412076] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:50.413535] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:51.412758] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:51.414102] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:51.884277] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:51.889033] 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-03-29 17:19:51.889341] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:51.889421] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:51.889465] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:51.889491] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:52.413374] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:52.414629] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:53.414031] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:53.415271] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:54.414577] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:54.415914] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:54.889605] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:54.894448] 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-03-29 17:19:54.894727] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:54.894800] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:54.894840] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:54.894867] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:55.415190] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:55.416420] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:56.415755] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:56.417170] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:57.416694] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:57.418070] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:57.895023] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:19:57.899774] 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-03-29 17:19:57.900038] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:19:57.900146] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:19:57.900191] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:19:57.900237] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:19:58.417127] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:58.418372] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:19:59.420110] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:19:59.421394] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:00.418420] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:00.419894] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:00.900322] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:20:00.906910] 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-03-29 17:20:00.907191] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:20:00.907270] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:20:00.907300] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:20:00.907325] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:20:01.419047] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:01.420520] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:02.419783] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:02.421179] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:03.420502] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:03.421944] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:03.907468] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:20:03.912245] 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-03-29 17:20:03.912537] D [socket.c:289:__socket_disconnect] 0-dstore-client-0: shutdown() returned -1. Transport endpoint is not connected
>[2012-03-29 17:20:03.912602] D [socket.c:193:__socket_rwv] 0-dstore-client-0: EOF from peer 192.168.2.35:24009
>[2012-03-29 17:20:03.912658] D [socket.c:1494:__socket_proto_state_machine] 0-dstore-client-0: reading from socket failed. Error (Transport endpoint is not connected), peer (192.168.2.35:24009)
>[2012-03-29 17:20:03.912701] D [socket.c:1768:socket_event_handler] 0-transport: disconnecting now
>[2012-03-29 17:20:04.421004] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:04.422478] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:05.421445] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:05.422758] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:06.421999] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:06.423530] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:06.912765] D [name.c:157:client_fill_address_family] 0-dstore-client-0: address-family not specified, guessing it to be inet/inet6
>[2012-03-29 17:20:06.917850] 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-03-29 17:20:06.918199] D [client.c:1856:client_rpc_notify] 0-dstore-client-0: got RPC_CLNT_CONNECT
>[2012-03-29 17:20:06.918316] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:20:06.918785] I [client-handshake.c:1090:select_server_supported_programs] 0-dstore-client-0: Using Program GlusterFS 3.2.6, Num (1298437), Version (310)
>[2012-03-29 17:20:06.918894] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (1 || 1)
>[2012-03-29 17:20:06.926866] I [client-handshake.c:913:client_setvolume_cbk] 0-dstore-client-0: Connected to 192.168.2.35:24009, attached to remote volume '/export1/dstore1'.
>[2012-03-29 17:20:06.926940] I [client-handshake.c:779:client_post_handshake] 0-dstore-client-0: 1 fds open - Delaying child_up until they are re-opened
>[2012-03-29 17:20:06.926994] D [client-handshake.c:710:protocol_client_reopen] 0-dstore-client-0: attempting reopen on /test/foo.txt
>[2012-03-29 17:20:06.927999] D [client-handshake.c:434:client3_1_reopen_cbk] 0-dstore-client-0: reopen on /test/foo.txt succeeded (remote-fd = 0)
>[2012-03-29 17:20:06.928079] I [client-lk.c:617:decrement_reopen_fd_count] 0-dstore-client-0: last fd open'd/lock-self-heal'd - notifying CHILD-UP
>[2012-03-29 17:20:06.928128] D [fuse-bridge.c:3357:notify] 0-fuse: got event 8 on graph 0
>[2012-03-29 17:20:07.422582] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:07.422689] I [afr-open.c:432:afr_openfd_sh] 0-dstore-replicate-0:  data missing-entry gfid self-heal triggered. path: /test/foo.txt, reason: Replicate up down flush, data lock is held
>[2012-03-29 17:20:07.423159] D [afr-self-heal-common.c:1864:afr_sh_post_nb_entrylk_conflicting_sh_cbk] 0-dstore-replicate-0: Non blocking entrylks done. Proceeding to FOP
>[2012-03-29 17:20:07.423256] D [afr-self-heal-common.c:1823:afr_sh_common_lookup] 0-dstore-replicate-0: looking up /test/foo.txt on subvolume dstore-client-0
>[2012-03-29 17:20:07.423391] D [afr-self-heal-common.c:1823:afr_sh_common_lookup] 0-dstore-replicate-0: looking up /test/foo.txt on subvolume dstore-client-1
>[2012-03-29 17:20:07.423921] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:07.423977] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:20:07.424004] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: -1
>[2012-03-29 17:20:07.424035] D [afr-self-heal-common.c:1736:afr_sh_find_fresh_parents] 0-dstore-replicate-0: /test/foo.txt: All subvols pending so do missing entry creation
>[2012-03-29 17:20:07.424071] D [afr-self-heal-common.c:1823:afr_sh_common_lookup] 0-dstore-replicate-0: looking up /test/foo.txt on subvolume dstore-client-0
>[2012-03-29 17:20:07.424222] D [afr-self-heal-common.c:1823:afr_sh_common_lookup] 0-dstore-replicate-0: looking up /test/foo.txt on subvolume dstore-client-1
>[2012-03-29 17:20:07.424760] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:07.424819] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character wise
>[2012-03-29 17:20:07.424857] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 1
>[2012-03-29 17:20:07.424896] I [afr-self-heal-common.c:1203:sh_missing_entries_create] 0-dstore-replicate-0: no missing files - /test/foo.txt. proceeding to metadata check
>[2012-03-29 17:20:07.424922] D [afr-lk-common.c:414:transaction_lk_op] 0-dstore-replicate-0: lk op is for a self heal
>[2012-03-29 17:20:07.425352] D [afr-self-heal-metadata.c:94:afr_sh_metadata_done] 0-dstore-replicate-0: proceeding to data check on /test/foo.txt
>[2012-03-29 17:20:07.426814] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:07.426871] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character wise
>[2012-03-29 17:20:07.426897] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 1
>[2012-03-29 17:20:07.427297] W [dict.c:418:dict_unref] (-->/usr/local/lib/glusterfs/3.2.6/xlator/protocol/client.so(client3_1_fstat_cbk+0x32a) [0x7f5f13a93588] (-->/usr/local/lib/glusterfs/3.2.6/xlator/cluster/replicate.so(afr_sh_data_fstat_cbk+0x21a) [0x7f5f1383114a] (-->/usr/local/lib/glusterfs/3.2.6/xlator/cluster/replicate.so(afr_sh_data_fix+0x5c8) [0x7f5f1383087b]))) 0-dict: dict is NULL
>[2012-03-29 17:20:07.427361] D [afr-self-heal-data.c:569:afr_sh_data_sync_prepare] 0-dstore-replicate-0: self-healing file /test/foo.txt from subvolume dstore-client-1 to 1 other
>[2012-03-29 17:20:07.429037] D [afr-self-heal-data.c:286:afr_sh_data_finish] 0-dstore-replicate-0: finishing data selfheal of /test/foo.txt
>[2012-03-29 17:20:07.429911] I [afr-self-heal-common.c:2077:afr_self_heal_completion_cbk] 0-dstore-replicate-0: background  data missing-entry gfid self-heal completed on /test/foo.txt
>[2012-03-29 17:20:07.429977] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:07.430794] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:07.432147] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:08.423318] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:08.424960] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:09.423917] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:09.425522] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:10.424490] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:10.426152] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:11.425068] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:11.426899] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:12.425924] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:12.427731] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:12.918795] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:20:13.426361] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:13.427902] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:14.426981] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:14.428682] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:15.427618] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:15.429864] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:15.491299] D [afr-transaction.c:976:afr_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non blocking inodelks done. Proceeding to FOP
>[2012-03-29 17:20:15.491756] D [afr-lk-common.c:409:transaction_lk_op] 0-dstore-replicate-0: lk op is for a transaction
>[2012-03-29 17:20:19.652199] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test/foo.txt: failed to get the gfid from dict
>[2012-03-29 17:20:19.652979] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:19.653050] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:20:19.653128] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:20:19.653183] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:20:19.653228] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test/foo.txt
>[2012-03-29 17:20:19.653277] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:20:19.653327] I [afr-common.c:869:afr_detect_self_heal_by_iatt] 0-dstore-replicate-0: ownership differs for /test/foo.txt 
>[2012-03-29 17:20:19.653396] I [afr-common.c:1038:afr_launch_self_heal] 0-dstore-replicate-0: background  meta-data self-heal triggered. path: /test/foo.txt
>[2012-03-29 17:20:19.653923] D [afr-self-heal-metadata.c:569:afr_sh_metadata_post_nonblocking_inodelk_cbk] 0-dstore-replicate-0: Non Blocking metadata inodelks done for /test/foo.txt. Proceeding to FOP
>[2012-03-29 17:20:19.654003] D [afr-self-heal-common.c:1823:afr_sh_common_lookup] 0-dstore-replicate-0: looking up /test/foo.txt on subvolume dstore-client-0
>[2012-03-29 17:20:19.654096] D [afr-self-heal-common.c:1823:afr_sh_common_lookup] 0-dstore-replicate-0: looking up /test/foo.txt on subvolume dstore-client-1
>[2012-03-29 17:20:19.654706] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:19.654774] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:20:19.654823] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 1
>[2012-03-29 17:20:19.655299] D [afr-self-heal-metadata.c:351:afr_sh_metadata_sync] 0-dstore-replicate-0: self-healing metadata of /test/foo.txt from dstore-client-0 to dstore-client-1
>[2012-03-29 17:20:19.656563] D [afr-lk-common.c:414:transaction_lk_op] 0-dstore-replicate-0: lk op is for a self heal
>[2012-03-29 17:20:19.656902] D [afr-self-heal-metadata.c:94:afr_sh_metadata_done] 0-dstore-replicate-0: proceeding to data check on /test/foo.txt
>[2012-03-29 17:20:19.656969] I [afr-self-heal-common.c:2077:afr_self_heal_completion_cbk] 0-dstore-replicate-0: background  meta-data self-heal completed on /test/foo.txt
>[2012-03-29 17:20:19.657026] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:19.657073] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:20:19.657179] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:20:19.657242] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:20:19.657289] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test/foo.txt
>[2012-03-29 17:20:19.657334] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:20:22.517704] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test/foo.txt: failed to get the gfid from dict
>[2012-03-29 17:20:22.518583] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:22.518665] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:20:22.518756] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:20:22.518830] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:20:22.518879] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test/foo.txt
>[2012-03-29 17:20:22.518925] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:20:24.65665] D [afr-common.c:181:afr_lookup_xattr_req_prepare] 0-dstore-replicate-0: /test/foo.txt: failed to get the gfid from dict
>[2012-03-29 17:20:24.66564] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:20:24.66627] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:20:24.66654] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:20:24.66674] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:20:24.66693] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /test/foo.txt
>[2012-03-29 17:20:24.66727] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:20:49.923711] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:20:55.924740] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:21:05.325349] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:21:05.325426] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:21:05.325461] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:21:05.325498] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:21:05.325530] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:21:05.325557] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:21:11.277535] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:21:11.277632] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:21:11.277671] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:21:11.277703] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:21:11.277739] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:21:11.277768] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:21:12.602418] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 0 character innocent
>[2012-03-29 17:21:12.602498] D [afr-self-heal-common.c:581:afr_find_child_character_type] 0-dstore-replicate-0: child 1 character innocent
>[2012-03-29 17:21:12.602524] D [afr-self-heal-common.c:734:afr_mark_sources] 0-dstore-replicate-0: Number of sources: 0
>[2012-03-29 17:21:12.602543] D [afr-self-heal-data.c:843:afr_lookup_select_read_child_by_txn_type] 0-dstore-replicate-0: returning read_child: 1
>[2012-03-29 17:21:12.602561] D [afr-common.c:998:afr_lookup_select_read_child] 0-dstore-replicate-0: Source selected as 1 for /
>[2012-03-29 17:21:12.602581] D [afr-common.c:789:afr_lookup_build_response_params] 0-dstore-replicate-0: Building lookup response from 1
>[2012-03-29 17:21:47.931554] D [client-handshake.c:179:client_start_ping] 0-dstore-client-0: returning as transport is already disconnected OR there are no frames (0 || 0)
>[2012-03-29 17:21:47.931653] D [client-handshake.c:179:client_start_ping] 0-dstore-client-1: returning as transport is already disconnected OR there are no frames (0 || 0)

Actions: View

Attachments on bug 807976: 573597 | 592682