Attachment 941976 Details for Bug 1147236 – mount log

mount log

note.txt (text/plain), 45.30 KB, created by Panpan Feng on 2014-09-28 10:09:25 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Panpan Feng

Created: 2014-09-28 10:09:25 UTC

Size: 45.30 KB

patch

obsolete

>[2014-09-28 07:39:28.574411] I [MSGID: 100030] [glusterfsd.c:2018:main] 0-/usr/sbin/glusterfs: Started running /usr/sbin/glusterfs version 3.6.0beta1 (args: /usr/sbin/glusterfs --volfile-server=10.10.10.10 --volfile-id=myvol /mnt/myvol --debug)
>[2014-09-28 07:39:28.574852] D [MSGID: 0] [glusterfsd.c:409:set_fuse_mount_options] 0-glusterfsd: fopen-keep-cache mode 2
>[2014-09-28 07:39:28.574868] D [MSGID: 0] [glusterfsd.c:463:set_fuse_mount_options] 0-glusterfsd: fuse direct io type 2
>[2014-09-28 07:39:28.574877] D [MSGID: 0] [glusterfsd.c:487:set_fuse_mount_options] 0-glusterfsd: fuse no-root-squash mode 0
>[2014-09-28 07:39:28.574985] D [options.c:1163:xlator_option_init_double] 0-fuse: option negative-timeout using set value 0.000000
>[2014-09-28 07:39:28.575056] D [options.c:1160:xlator_option_init_bool] 0-fuse: option no-root-squash using set value disable
>[2014-09-28 07:39:28.575396] D [logging.c:1781:__gf_log_inject_timer_event] 0-logging-infra: Starting timer now. Timeout = 120, current buf size = 5
>[2014-09-28 07:39:28.575654] D [rpc-clnt.c:972:rpc_clnt_connection_init] 0-glusterfs: defaulting frame-timeout to 30mins
>[2014-09-28 07:39:28.575685] D [rpc-clnt.c:986:rpc_clnt_connection_init] 0-glusterfs: disable ping-timeout
>[2014-09-28 07:39:28.575700] D [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.6.0beta1/rpc-transport/socket.so
>[2014-09-28 07:39:28.577787] D [socket.c:3702:socket_init] 0-glusterfs: SSL support on the I/O path is NOT enabled
>[2014-09-28 07:39:28.577802] D [socket.c:3705:socket_init] 0-glusterfs: SSL support for glusterd is NOT enabled
>[2014-09-28 07:39:28.577808] D [socket.c:3722:socket_init] 0-glusterfs: using system polling thread
>[2014-09-28 07:39:28.577822] D [rpc-clnt.c:1452:rpcclnt_cbk_program_register] 0-glusterfs: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2014-09-28 07:39:28.580834] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.580849] D [socket.c:2720:socket_fix_ssl_opts] 0-glusterfs: disabling SSL for portmapper connection
>[2014-09-28 07:39:28.650876] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-glusterfs: ping timeout is 0, returning
>[2014-09-28 07:39:28.723892] D [options.c:1160:xlator_option_init_bool] 0-myvol: option count-fop-hits using set value off
>[2014-09-28 07:39:28.723911] D [options.c:1160:xlator_option_init_bool] 0-myvol: option latency-measurement using set value off
>[2014-09-28 07:39:28.724040] D [quick-read.c:823:check_cache_size_ok] 0-myvol-quick-read: Max cache size is 8589934592
>[2014-09-28 07:39:28.724098] D [io-cache.c:1624:check_cache_size_ok] 0-myvol-io-cache: Max cache size is 8589934592
>[2014-09-28 07:39:28.724253] I [dht-shared.c:337:dht_init_regex] 0-myvol-dht: using regex rsync-hash-regex = ^\.(.+)\.[^.]+$
>[2014-09-28 07:39:28.729041] D [client.c:2494:client_init_grace_timer] 0-myvol-client-3: lk-heal = off
>[2014-09-28 07:39:28.729059] D [client.c:2505:client_init_grace_timer] 0-myvol-client-3: Client grace timeout value = 10
>[2014-09-28 07:39:28.729077] D [options.c:1162:xlator_option_init_path] 0-myvol-client-3: option remote-subvolume using set value /mnt/xfsd/myvol-3
>[2014-09-28 07:39:28.729324] D [rpc-clnt.c:972:rpc_clnt_connection_init] 0-myvol-client-3: defaulting frame-timeout to 30mins
>[2014-09-28 07:39:28.729333] D [rpc-clnt.c:986:rpc_clnt_connection_init] 0-myvol-client-3: disable ping-timeout
>[2014-09-28 07:39:28.729348] D [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.6.0beta1/rpc-transport/socket.so
>[2014-09-28 07:39:28.729391] D [socket.c:3702:socket_init] 0-myvol-client-3: SSL support on the I/O path is NOT enabled
>[2014-09-28 07:39:28.729399] D [socket.c:3705:socket_init] 0-myvol-client-3: SSL support for glusterd is NOT enabled
>[2014-09-28 07:39:28.729405] D [socket.c:3722:socket_init] 0-myvol-client-3: using system polling thread
>[2014-09-28 07:39:28.729414] D [rpc-clnt.c:1452:rpcclnt_cbk_program_register] 0-myvol-client-3: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2014-09-28 07:39:28.729421] D [client.c:2469:client_init_rpc] 0-myvol-client-3: client init successful
>[2014-09-28 07:39:28.729434] D [client.c:2494:client_init_grace_timer] 0-myvol-client-2: lk-heal = off
>[2014-09-28 07:39:28.729441] D [client.c:2505:client_init_grace_timer] 0-myvol-client-2: Client grace timeout value = 10
>[2014-09-28 07:39:28.729455] D [options.c:1162:xlator_option_init_path] 0-myvol-client-2: option remote-subvolume using set value /mnt/xfsd/myvol-2
>[2014-09-28 07:39:28.729697] D [rpc-clnt.c:972:rpc_clnt_connection_init] 0-myvol-client-2: defaulting frame-timeout to 30mins
>[2014-09-28 07:39:28.729705] D [rpc-clnt.c:986:rpc_clnt_connection_init] 0-myvol-client-2: disable ping-timeout
>[2014-09-28 07:39:28.729714] D [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.6.0beta1/rpc-transport/socket.so
>[2014-09-28 07:39:28.729749] D [socket.c:3702:socket_init] 0-myvol-client-2: SSL support on the I/O path is NOT enabled
>[2014-09-28 07:39:28.729756] D [socket.c:3705:socket_init] 0-myvol-client-2: SSL support for glusterd is NOT enabled
>[2014-09-28 07:39:28.729762] D [socket.c:3722:socket_init] 0-myvol-client-2: using system polling thread
>[2014-09-28 07:39:28.729770] D [rpc-clnt.c:1452:rpcclnt_cbk_program_register] 0-myvol-client-2: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2014-09-28 07:39:28.729777] D [client.c:2469:client_init_rpc] 0-myvol-client-2: client init successful
>[2014-09-28 07:39:28.729787] D [client.c:2494:client_init_grace_timer] 0-myvol-client-1: lk-heal = off
>[2014-09-28 07:39:28.729793] D [client.c:2505:client_init_grace_timer] 0-myvol-client-1: Client grace timeout value = 10
>[2014-09-28 07:39:28.729807] D [options.c:1162:xlator_option_init_path] 0-myvol-client-1: option remote-subvolume using set value /mnt/xfsd/myvol-1
>[2014-09-28 07:39:28.730041] D [rpc-clnt.c:972:rpc_clnt_connection_init] 0-myvol-client-1: defaulting frame-timeout to 30mins
>[2014-09-28 07:39:28.730049] D [rpc-clnt.c:986:rpc_clnt_connection_init] 0-myvol-client-1: disable ping-timeout
>[2014-09-28 07:39:28.730060] D [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.6.0beta1/rpc-transport/socket.so
>[2014-09-28 07:39:28.730092] D [socket.c:3702:socket_init] 0-myvol-client-1: SSL support on the I/O path is NOT enabled
>[2014-09-28 07:39:28.730099] D [socket.c:3705:socket_init] 0-myvol-client-1: SSL support for glusterd is NOT enabled
>[2014-09-28 07:39:28.730106] D [socket.c:3722:socket_init] 0-myvol-client-1: using system polling thread
>[2014-09-28 07:39:28.730113] D [rpc-clnt.c:1452:rpcclnt_cbk_program_register] 0-myvol-client-1: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2014-09-28 07:39:28.730120] D [client.c:2469:client_init_rpc] 0-myvol-client-1: client init successful
>[2014-09-28 07:39:28.730129] D [client.c:2494:client_init_grace_timer] 0-myvol-client-0: lk-heal = off
>[2014-09-28 07:39:28.730136] D [client.c:2505:client_init_grace_timer] 0-myvol-client-0: Client grace timeout value = 10
>[2014-09-28 07:39:28.730149] D [options.c:1162:xlator_option_init_path] 0-myvol-client-0: option remote-subvolume using set value /mnt/xfsd/myvol-0
>[2014-09-28 07:39:28.730389] D [rpc-clnt.c:972:rpc_clnt_connection_init] 0-myvol-client-0: defaulting frame-timeout to 30mins
>[2014-09-28 07:39:28.730397] D [rpc-clnt.c:986:rpc_clnt_connection_init] 0-myvol-client-0: disable ping-timeout
>[2014-09-28 07:39:28.730409] D [rpc-transport.c:262:rpc_transport_load] 0-rpc-transport: attempt to load file /usr/lib64/glusterfs/3.6.0beta1/rpc-transport/socket.so
>[2014-09-28 07:39:28.730468] D [socket.c:3702:socket_init] 0-myvol-client-0: SSL support on the I/O path is NOT enabled
>[2014-09-28 07:39:28.730476] D [socket.c:3705:socket_init] 0-myvol-client-0: SSL support for glusterd is NOT enabled
>[2014-09-28 07:39:28.730482] D [socket.c:3722:socket_init] 0-myvol-client-0: using system polling thread
>[2014-09-28 07:39:28.730489] D [rpc-clnt.c:1452:rpcclnt_cbk_program_register] 0-myvol-client-0: New program registered: GlusterFS Callback, Num: 52743234, Ver: 1
>[2014-09-28 07:39:28.730499] D [client.c:2469:client_init_rpc] 0-myvol-client-0: client init successful
>[2014-09-28 07:39:28.730522] D [fuse-bridge.c:5098:notify] 0-fuse: got event 12 on graph 0
>[2014-09-28 07:39:28.730534] I [client.c:2280:notify] 0-myvol-client-0: parent translators are ready, attempting connect on transport
>[2014-09-28 07:39:28.730544] D [name.c:148:client_fill_address_family] 0-myvol-client-0: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.733361] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.733374] D [socket.c:2720:socket_fix_ssl_opts] 0-myvol-client-0: disabling SSL for portmapper connection
>[2014-09-28 07:39:28.733442] I [client.c:2280:notify] 0-myvol-client-1: parent translators are ready, attempting connect on transport
>[2014-09-28 07:39:28.733465] D [name.c:148:client_fill_address_family] 0-myvol-client-1: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.736171] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.736184] D [socket.c:2720:socket_fix_ssl_opts] 0-myvol-client-1: disabling SSL for portmapper connection
>[2014-09-28 07:39:28.736229] I [client.c:2280:notify] 0-myvol-client-2: parent translators are ready, attempting connect on transport
>[2014-09-28 07:39:28.736241] D [name.c:148:client_fill_address_family] 0-myvol-client-2: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.738917] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.738929] D [socket.c:2720:socket_fix_ssl_opts] 0-myvol-client-2: disabling SSL for portmapper connection
>[2014-09-28 07:39:28.738968] I [client.c:2280:notify] 0-myvol-client-3: parent translators are ready, attempting connect on transport
>[2014-09-28 07:39:28.738992] D [name.c:148:client_fill_address_family] 0-myvol-client-3: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.741658] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.741670] D [socket.c:2720:socket_fix_ssl_opts] 0-myvol-client-3: disabling SSL for portmapper connection
>Final graph:
>+------------------------------------------------------------------------------+
>  1: volume myvol-client-0
>  2:     type protocol/client
>  3:     option transport-type socket
>  4:     option remote-subvolume /mnt/xfsd/myvol-0
>  5:     option remote-host 10.10.10.10
>  6: end-volume
>  7:
>  8: volume myvol-client-1
>  9:     type protocol/client
> 10:     option transport-type socket
> 11:     option remote-subvolume /mnt/xfsd/myvol-1
> 12:     option remote-host 10.10.10.10
> 13: end-volume
> 14:
> 15: volume myvol-replicate-0
> 16:     type cluster/replicate
> 17:     subvolumes myvol-client-0 myvol-client-1
> 18: end-volume
> 19:
> 20: volume myvol-client-2
> 21:     type protocol/client
> 22:     option transport-type socket
> 23:     option remote-subvolume /mnt/xfsd/myvol-2
> 24:     option remote-host 10.10.10.10
> 25: end-volume
> 26:
> 27: volume myvol-client-3
> 28:     type protocol/client
> 29:     option transport-type socket
> 30:     option remote-subvolume /mnt/xfsd/myvol-3
> 31:     option remote-host 10.10.10.10
> 32: end-volume
> 33:
> 34: volume myvol-replicate-1
> 35:     type cluster/replicate
> 36:     subvolumes myvol-client-2 myvol-client-3
> 37: end-volume
> 38:
> 39: volume myvol-dht
> 40:     type cluster/distribute
> 41:     subvolumes myvol-replicate-0 myvol-replicate-1
> 42: end-volume
> 43:
> 44: volume myvol-write-behind
> 45:     type performance/write-behind
> 46:     subvolumes myvol-dht
> 47: end-volume
> 48:
> 49: volume myvol-read-ahead
> 50:     type performance/read-ahead
> 51:     subvolumes myvol-write-behind
> 52: end-volume
> 53:
> 54: volume myvol-io-cache
> 55:     type performance/io-cache
> 56:     subvolumes myvol-read-ahead
> 57: end-volume
> 58:
> 59: volume myvol-quick-read
> 60:     type performance/quick-read
> 61:     subvolumes myvol-io-cache
> 62: end-volume
> 63:
> 64: volume myvol-md-cache
> 65:     type performance/md-cache
> 66:     subvolumes myvol-quick-read
> 67: end-volume
> 68:
> 69: volume myvol
> 70:     type debug/io-stats
> 71:     option count-fop-hits off
> 72:     option latency-measurement off
> 73:     subvolumes myvol-md-cache
> 74: end-volume
> 75:
> 76: volume meta-autoload
> 77:     type meta
> 78:     subvolumes myvol
> 79: end-volume
> 80:
>+------------------------------------------------------------------------------+
>[2014-09-28 07:39:28.741983] D [glusterfsd-mgmt.c:2173:glusterfs_mgmt_pmap_signin] 0-fsd-mgmt: portmapper signin arguments not given
>[2014-09-28 07:39:28.803255] D [client.c:2162:client_rpc_notify] 0-myvol-client-0: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:28.803334] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:28.806076] D [client.c:2162:client_rpc_notify] 0-myvol-client-1: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:28.806118] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:28.808726] D [client.c:2162:client_rpc_notify] 0-myvol-client-2: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:28.808765] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:28.812387] D [client.c:2162:client_rpc_notify] 0-myvol-client-3: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:28.812443] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:28.873446] D [client-handshake.c:1449:server_has_portmap] 0-myvol-client-0: detected portmapper on server
>[2014-09-28 07:39:28.873524] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:28.876121] D [client-handshake.c:1449:server_has_portmap] 0-myvol-client-1: detected portmapper on server
>[2014-09-28 07:39:28.876156] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:28.880481] D [client-handshake.c:1449:server_has_portmap] 0-myvol-client-2: detected portmapper on server
>[2014-09-28 07:39:28.880532] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:28.882740] D [client-handshake.c:1449:server_has_portmap] 0-myvol-client-3: detected portmapper on server
>[2014-09-28 07:39:28.882776] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:28.943738] I [rpc-clnt.c:1761:rpc_clnt_reconfig] 0-myvol-client-0: changing port to 24009 (from 0)
>[2014-09-28 07:39:28.943784] D [socket.c:2247:socket_event_handler] 0-transport: disconnecting now
>[2014-09-28 07:39:28.943823] D [client.c:2237:client_rpc_notify] 0-myvol-client-0: disconnected (skipped notify)
>[2014-09-28 07:39:28.943834] D [name.c:148:client_fill_address_family] 0-myvol-client-0: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.946605] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.947981] I [rpc-clnt.c:1761:rpc_clnt_reconfig] 0-myvol-client-1: changing port to 24010 (from 0)
>[2014-09-28 07:39:28.948006] D [socket.c:2247:socket_event_handler] 0-transport: disconnecting now
>[2014-09-28 07:39:28.948036] D [client.c:2237:client_rpc_notify] 0-myvol-client-1: disconnected (skipped notify)
>[2014-09-28 07:39:28.948045] D [name.c:148:client_fill_address_family] 0-myvol-client-1: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.950893] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.953121] I [rpc-clnt.c:1761:rpc_clnt_reconfig] 0-myvol-client-2: changing port to 24011 (from 0)
>[2014-09-28 07:39:28.953152] D [socket.c:2247:socket_event_handler] 0-transport: disconnecting now
>[2014-09-28 07:39:28.953172] D [client.c:2237:client_rpc_notify] 0-myvol-client-2: disconnected (skipped notify)
>[2014-09-28 07:39:28.953180] D [name.c:148:client_fill_address_family] 0-myvol-client-2: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.955823] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:28.955888] I [rpc-clnt.c:1761:rpc_clnt_reconfig] 0-myvol-client-3: changing port to 24012 (from 0)
>[2014-09-28 07:39:28.955909] D [socket.c:2247:socket_event_handler] 0-transport: disconnecting now
>[2014-09-28 07:39:28.955925] D [client.c:2237:client_rpc_notify] 0-myvol-client-3: disconnected (skipped notify)
>[2014-09-28 07:39:28.955933] D [name.c:148:client_fill_address_family] 0-myvol-client-3: address-family not specified, guessing it to be inet from (remote-host: 10.10.10.10)
>[2014-09-28 07:39:28.958544] D [common-utils.c:252:gf_resolve_ip6] 0-resolver: returning ip-10.10.10.10 (port-24007) for hostname: 10.10.10.10 and port: 24007
>[2014-09-28 07:39:29.016445] D [client.c:2162:client_rpc_notify] 0-myvol-client-0: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:29.016507] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.020728] D [client.c:2162:client_rpc_notify] 0-myvol-client-1: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:29.020770] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.025710] D [client.c:2162:client_rpc_notify] 0-myvol-client-2: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:29.025763] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:29.029206] D [client.c:2162:client_rpc_notify] 0-myvol-client-3: got RPC_CLNT_CONNECT
>[2014-09-28 07:39:29.029247] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.087574] I [client-handshake.c:1415:select_server_supported_programs] 0-myvol-client-0: Using Program GlusterFS 3.3.0, Num (1298437), Version (330)
>[2014-09-28 07:39:29.087666] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.090556] I [client-handshake.c:1415:select_server_supported_programs] 0-myvol-client-1: Using Program GlusterFS 3.3.0, Num (1298437), Version (330)
>[2014-09-28 07:39:29.090603] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.095594] I [client-handshake.c:1415:select_server_supported_programs] 0-myvol-client-2: Using Program GlusterFS 3.3.0, Num (1298437), Version (330)
>[2014-09-28 07:39:29.095648] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:29.099101] I [client-handshake.c:1415:select_server_supported_programs] 0-myvol-client-3: Using Program GlusterFS 3.3.0, Num (1298437), Version (330)
>[2014-09-28 07:39:29.099154] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.157670] D [client-handshake.c:1174:client_setvolume_cbk] 0-myvol-client-0: clnt-lk-version = 1, server-lk-version = 0
>[2014-09-28 07:39:29.157705] I [client-handshake.c:1200:client_setvolume_cbk] 0-myvol-client-0: Connected to myvol-client-0, attached to remote volume '/mnt/xfsd/myvol-0'.
>[2014-09-28 07:39:29.157722] I [client-handshake.c:1212:client_setvolume_cbk] 0-myvol-client-0: Server and Client lk-version numbers are not same, reopening the fds
>[2014-09-28 07:39:29.157730] D [client-handshake.c:1062:client_post_handshake] 0-myvol-client-0: No fds to open - notifying all parents child up
>[2014-09-28 07:39:29.157743] D [client-handshake.c:230:client_set_lk_version] 0-myvol-client-0: Sending SET_LK_VERSION
>[2014-09-28 07:39:29.157773] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.157788] I [MSGID: 108005] [afr-common.c:3552:afr_notify] 0-myvol-replicate-0: Subvolume 'myvol-client-0' came back up; going online.
>[2014-09-28 07:39:29.160538] D [client-handshake.c:1174:client_setvolume_cbk] 0-myvol-client-1: clnt-lk-version = 1, server-lk-version = 0
>[2014-09-28 07:39:29.160553] I [client-handshake.c:1200:client_setvolume_cbk] 0-myvol-client-1: Connected to myvol-client-1, attached to remote volume '/mnt/xfsd/myvol-1'.
>[2014-09-28 07:39:29.160561] I [client-handshake.c:1212:client_setvolume_cbk] 0-myvol-client-1: Server and Client lk-version numbers are not same, reopening the fds
>[2014-09-28 07:39:29.160568] D [client-handshake.c:1062:client_post_handshake] 0-myvol-client-1: No fds to open - notifying all parents child up
>[2014-09-28 07:39:29.160577] D [client-handshake.c:230:client_set_lk_version] 0-myvol-client-1: Sending SET_LK_VERSION
>[2014-09-28 07:39:29.160600] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.160664] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.160684] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.165599] D [client-handshake.c:1174:client_setvolume_cbk] 0-myvol-client-2: clnt-lk-version = 1, server-lk-version = 0
>[2014-09-28 07:39:29.165614] I [client-handshake.c:1200:client_setvolume_cbk] 0-myvol-client-2: Connected to myvol-client-2, attached to remote volume '/mnt/xfsd/myvol-2'.
>[2014-09-28 07:39:29.165623] I [client-handshake.c:1212:client_setvolume_cbk] 0-myvol-client-2: Server and Client lk-version numbers are not same, reopening the fds
>[2014-09-28 07:39:29.165630] D [client-handshake.c:1062:client_post_handshake] 0-myvol-client-2: No fds to open - notifying all parents child up
>[2014-09-28 07:39:29.165639] D [client-handshake.c:230:client_set_lk_version] 0-myvol-client-2: Sending SET_LK_VERSION
>[2014-09-28 07:39:29.165662] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:29.165675] I [MSGID: 108005] [afr-common.c:3552:afr_notify] 0-myvol-replicate-1: Subvolume 'myvol-client-2' came back up; going online.
>[2014-09-28 07:39:29.169011] D [client-handshake.c:1174:client_setvolume_cbk] 0-myvol-client-3: clnt-lk-version = 1, server-lk-version = 0
>[2014-09-28 07:39:29.169026] I [client-handshake.c:1200:client_setvolume_cbk] 0-myvol-client-3: Connected to myvol-client-3, attached to remote volume '/mnt/xfsd/myvol-3'.
>[2014-09-28 07:39:29.169046] I [client-handshake.c:1212:client_setvolume_cbk] 0-myvol-client-3: Server and Client lk-version numbers are not same, reopening the fds
>[2014-09-28 07:39:29.169054] D [client-handshake.c:1062:client_post_handshake] 0-myvol-client-3: No fds to open - notifying all parents child up
>[2014-09-28 07:39:29.169063] D [client-handshake.c:230:client_set_lk_version] 0-myvol-client-3: Sending SET_LK_VERSION
>[2014-09-28 07:39:29.169087] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.169124] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:29.169149] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.169162] D [fuse-bridge.c:5098:notify] 0-fuse: got event 5 on graph 0
>[2014-09-28 07:39:29.174438] I [fuse-bridge.c:5080:fuse_graph_setup] 0-fuse: switched to graph 0
>[2014-09-28 07:39:29.174589] D [fuse-bridge.c:4706:fuse_get_mount_status] 0-fuse: mount status is 0
>[2014-09-28 07:39:29.174699] D [fuse-bridge.c:3968:fuse_init] 0-glusterfs-fuse: Detected support for FUSE_AUTO_INVAL_DATA. Enabling fopen_keep_cache automatically.
>[2014-09-28 07:39:29.174718] I [fuse-bridge.c:4009:fuse_init] 0-glusterfs-fuse: FUSE inited with protocol versions: glusterfs 7.22 kernel 7.13
>[2014-09-28 07:39:29.174828] D [MSGID: 0] [dht-common.c:2182:dht_lookup] 0-myvol-dht: Calling fresh lookup for / on myvol-replicate-0
>[2014-09-28 07:39:29.174945] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.174976] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.227630] I [client-handshake.c:188:client_set_lk_version_cbk] 0-myvol-client-0: Server lk version = 1
>[2014-09-28 07:39:29.230473] I [client-handshake.c:188:client_set_lk_version_cbk] 0-myvol-client-1: Server lk version = 1
>[2014-09-28 07:39:29.230704] D [MSGID: 0] [dht-diskusage.c:96:dht_du_info_cbk] 0-myvol-dht: subvolume 'myvol-replicate-0': avail_percent is: 99.00 and avail_space is: 44000304627712 and avail_inodes is: 99.00
>[2014-09-28 07:39:29.235459] I [client-handshake.c:188:client_set_lk_version_cbk] 0-myvol-client-2: Server lk version = 1
>[2014-09-28 07:39:29.239007] I [client-handshake.c:188:client_set_lk_version_cbk] 0-myvol-client-3: Server lk version = 1
>[2014-09-28 07:39:29.239182] D [MSGID: 0] [dht-diskusage.c:96:dht_du_info_cbk] 0-myvol-dht: subvolume 'myvol-replicate-1': avail_percent is: 99.00 and avail_space is: 44000304627712 and avail_inodes is: 99.00
>[2014-09-28 07:39:29.245931] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.245981] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.316033] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.316099] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.316123] D [MSGID: 0] [dht-common.c:1818:dht_lookup_cbk] 0-myvol-dht: fresh_lookup returned for / with op_ret 0 and op_errno 117
>[2014-09-28 07:39:29.316189] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:39:29.316212] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:39:29.316253] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:29.316279] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.386237] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:39:29.386283] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.456332] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:39:29.456423] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:41:28.585117] D [logging.c:1816:gf_log_flush_timeout_cbk] 0-logging-infra: Log timer timed out. About to flush outstanding messages if present
>[2014-09-28 07:41:28.585181] D [logging.c:1781:__gf_log_inject_timer_event] 0-logging-infra: Starting timer now. Timeout = 120, current buf size = 5
>[2014-09-28 07:42:42.361714] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:42:42.361761] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:42:42.361807] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:42:42.361838] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:42:42.433338] D [MSGID: 0] [dht-common.c:621:dht_revalidate_cbk] 0-myvol-dht: revalidate lookup of / returned with op_ret 0 and op_errno 117
>[2014-09-28 07:42:43.776943] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:42:43.776994] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:42:43.777041] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:42:43.777070] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:42:43.849182] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:42:43.849226] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:42:43.849260] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:42:43.849285] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:42:43.921891] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:42:43.995748] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:42:44.066240] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:42:44.144457] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:42:44.216674] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:42:44.216734] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:42:44.216770] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:42:44.216803] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.414879] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:43:19.414923] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:43:19.414974] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.415003] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.487414] D [MSGID: 0] [dht-common.c:2182:dht_lookup] 0-myvol-dht: Calling fresh lookup for /file on myvol-replicate-1
>[2014-09-28 07:43:19.487518] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.487552] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.558459] D [MSGID: 0] [dht-common.c:1818:dht_lookup_cbk] 0-myvol-dht: fresh_lookup returned for /file with op_ret -1 and op_errno 2
>[2014-09-28 07:43:19.558497] I [dht-common.c:1822:dht_lookup_cbk] 0-myvol-dht: Entry /file missing on subvol myvol-replicate-1
>[2014-09-28 07:43:19.558517] D [MSGID: 0] [dht-common.c:1607:dht_lookup_everywhere] 0-myvol-dht: winding lookup call to 2 subvols
>[2014-09-28 07:43:19.558613] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:43:19.558673] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:43:19.558744] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.558786] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.634376] D [MSGID: 0] [dht-common.c:1413:dht_lookup_everywhere_cbk] 0-myvol-dht: returned with op_ret -1 and op_errno 2 (/file) from subvol myvol-replicate-0
>[2014-09-28 07:43:19.634573] D [MSGID: 0] [dht-common.c:1413:dht_lookup_everywhere_cbk] 0-myvol-dht: returned with op_ret -1 and op_errno 2 (/file) from subvol myvol-replicate-1
>[2014-09-28 07:43:19.634605] D [MSGID: 0] [dht-common.c:1086:dht_lookup_everywhere_done] 0-myvol-dht: STATUS: hashed_subvol myvol-replicate-1 cached_subvol null
>[2014-09-28 07:43:19.634624] D [MSGID: 0] [dht-common.c:1147:dht_lookup_everywhere_done] 0-myvol-dht: There was no cached file and  unlink on hashed is not skipped /file
>[2014-09-28 07:43:19.634663] D [fuse-resolve.c:83:fuse_resolve_entry_cbk] 0-fuse: 00000000-0000-0000-0000-000000000001/file: failed to resolve (No such file or directory)
>[2014-09-28 07:43:19.634833] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.634877] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.708608] I [dht-common.c:1822:dht_lookup_cbk] 0-myvol-dht: Entry /file missing on subvol myvol-replicate-1
>[2014-09-28 07:43:19.708725] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:43:19.708759] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:43:19.708797] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.708828] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.781420] D [logging.c:1937:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
>[2014-09-28 07:43:19.708640] D [MSGID: 0] [dht-common.c:1607:dht_lookup_everywhere] 0-myvol-dht: winding lookup call to 2 subvols
>[2014-09-28 07:43:19.781418] D [MSGID: 0] [dht-common.c:1413:dht_lookup_everywhere_cbk] 0-myvol-dht: returned with op_ret -1 and op_errno 2 (/file) from subvol myvol-replicate-0
>[2014-09-28 07:43:19.781629] D [MSGID: 0] [dht-common.c:1413:dht_lookup_everywhere_cbk] 0-myvol-dht: returned with op_ret -1 and op_errno 2 (/file) from subvol myvol-replicate-1
>[2014-09-28 07:43:19.781653] D [MSGID: 0] [dht-common.c:1086:dht_lookup_everywhere_done] 0-myvol-dht: STATUS: hashed_subvol myvol-replicate-1 cached_subvol null
>[2014-09-28 07:43:19.781913] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.781959] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.851925] I [dht-common.c:1822:dht_lookup_cbk] 0-myvol-dht: Entry /file missing on subvol myvol-replicate-1
>[2014-09-28 07:43:19.851954] D [logging.c:1937:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
>The message "D [MSGID: 0] [dht-common.c:1818:dht_lookup_cbk] 0-myvol-dht: fresh_lookup returned for /file with op_ret -1 and op_errno 2" repeated 2 times between [2014-09-28 07:43:19.558459] and [2014-09-28 07:43:19.851922]
>[2014-09-28 07:43:19.851954] D [MSGID: 0] [dht-common.c:1607:dht_lookup_everywhere] 0-myvol-dht: winding lookup call to 2 subvols
>[2014-09-28 07:43:19.852049] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:43:19.852079] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:43:19.852118] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.852143] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.922764] D [MSGID: 0] [dht-common.c:1413:dht_lookup_everywhere_cbk] 0-myvol-dht: returned with op_ret -1 and op_errno 2 (/file) from subvol myvol-replicate-0
>[2014-09-28 07:43:19.922925] D [MSGID: 0] [dht-common.c:1413:dht_lookup_everywhere_cbk] 0-myvol-dht: returned with op_ret -1 and op_errno 2 (/file) from subvol myvol-replicate-1
>[2014-09-28 07:43:19.922974] D [fuse-resolve.c:83:fuse_resolve_entry_cbk] 0-fuse: 00000000-0000-0000-0000-000000000001/file: failed to resolve (No such file or directory)
>[2014-09-28 07:43:19.923057] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:43:19.923082] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:43:19.923107] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.923128] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.923203] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.923226] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:19.997012] D [logging.c:1937:_gf_msg_internal] 0-logging-infra: Buffer overflow of a buffer whose size limit is 5. About to flush least recently used log message to disk
>The message "D [MSGID: 0] [dht-common.c:1147:dht_lookup_everywhere_done] 0-myvol-dht: There was no cached file and  unlink on hashed is not skipped /file" repeated 2 times between [2014-09-28 07:43:19.634624] and [2014-09-28 07:43:19.922951]
>[2014-09-28 07:43:19.997011] D [MSGID: 0] [dht-diskusage.c:96:dht_du_info_cbk] 0-myvol-dht: subvolume 'myvol-replicate-0': avail_percent is: 99.00 and avail_space is: 44000304627712 and avail_inodes is: 99.00
>[2014-09-28 07:43:19.997134] D [MSGID: 0] [dht-diskusage.c:96:dht_du_info_cbk] 0-myvol-dht: subvolume 'myvol-replicate-1': avail_percent is: 99.00 and avail_space is: 44000304627712 and avail_inodes is: 99.00
>[2014-09-28 07:43:19.997179] D [afr-transaction.c:1166:afr_post_nonblocking_entrylk_cbk] 0-myvol-replicate-1: Non blocking entrylks done. Proceeding to FOP
>[2014-09-28 07:43:19.997242] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:19.997278] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.067587] D [afr-lk-common.c:447:transaction_lk_op] 0-myvol-replicate-1: lk op is for a transaction
>[2014-09-28 07:43:20.067636] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:20.067660] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.067786] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:20.067827] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.140751] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:20.140798] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.216287] D [afr-transaction.c:1116:afr_post_nonblocking_inodelk_cbk] 0-myvol-replicate-1: Non blocking inodelks done. Proceeding to FOP
>[2014-09-28 07:43:20.216362] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:20.216391] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.286481] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:20.286530] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.356844] W [client-rpc-fops.c:850:client3_3_writev_cbk] 0-myvol-client-3: remote operation failed: Transport endpoint is not connected
>[2014-09-28 07:43:20.356979] W [client-rpc-fops.c:850:client3_3_writev_cbk] 0-myvol-client-2: remote operation failed: Transport endpoint is not connected
>[2014-09-28 07:43:20.357009] D [afr-lk-common.c:447:transaction_lk_op] 0-myvol-replicate-1: lk op is for a transaction
>[2014-09-28 07:43:20.357051] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:20.357077] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.428013] W [fuse-bridge.c:1261:fuse_err_cbk] 0-glusterfs-fuse: 14: FLUSH() ERR => -1 (Transport endpoint is not connected)
>[2014-09-28 07:43:20.428209] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:43:20.428277] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:43:28.593512] D [logging.c:1816:gf_log_flush_timeout_cbk] 0-logging-infra: Log timer timed out. About to flush outstanding messages if present
>The message "D [MSGID: 0] [dht-common.c:621:dht_revalidate_cbk] 0-myvol-dht: revalidate lookup of / returned with op_ret 0 and op_errno 117" repeated 5 times between [2014-09-28 07:42:42.433338] and [2014-09-28 07:43:19.487219]
>The message "D [MSGID: 0] [dht-common.c:2182:dht_lookup] 0-myvol-dht: Calling fresh lookup for /file on myvol-replicate-1" repeated 2 times between [2014-09-28 07:43:19.487414] and [2014-09-28 07:43:19.781835]
>[2014-09-28 07:43:19.922950] D [MSGID: 0] [dht-common.c:1086:dht_lookup_everywhere_done] 0-myvol-dht: STATUS: hashed_subvol myvol-replicate-1 cached_subvol null
>[2014-09-28 07:43:28.593615] D [logging.c:1781:__gf_log_inject_timer_event] 0-logging-infra: Starting timer now. Timeout = 120, current buf size = 5
>[2014-09-28 07:44:26.445796] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:44:26.445840] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:44:26.445886] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:26.445913] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:26.517010] D [MSGID: 0] [dht-common.c:621:dht_revalidate_cbk] 0-myvol-dht: revalidate lookup of / returned with op_ret 0 and op_errno 117
>[2014-09-28 07:44:26.517370] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:44:26.517408] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:44:26.517442] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:26.517466] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:26.591451] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:44:26.662747] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:44:26.734464] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:26.804819] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:26.876265] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:44:26.876297] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:44:26.876328] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:26.876355] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:26.876492] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-0: ping timeout is 0, returning
>[2014-09-28 07:44:26.876517] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-1: ping timeout is 0, returning
>[2014-09-28 07:44:26.876557] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:26.876580] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:26.950203] D [MSGID: 0] [dht-common.c:2108:dht_lookup] 0-myvol-dht: calling revalidate lookup for /file at myvol-replicate-1
>[2014-09-28 07:44:26.950308] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:26.950343] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:27.022986] D [MSGID: 0] [dht-common.c:621:dht_revalidate_cbk] 0-myvol-dht: revalidate lookup of /file returned with op_ret 0 and op_errno 0
>[2014-09-28 07:44:27.732158] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:27.732197] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:27.803567] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:27.877858] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>[2014-09-28 07:44:27.877887] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:27.949705] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-3: ping timeout is 0, returning
>[2014-09-28 07:44:27.949794] D [rpc-clnt-ping.c:231:rpc_clnt_start_ping] 0-myvol-client-2: ping timeout is 0, returning
>

Actions: View

Attachments on bug 1147236: 941976