Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-24 Thread Riccardo Murri
...and here's the statedump of the client, snapd and brick snap
processes from the 4.1 test cluster.
(File names are as outputted from the GlusterD processes, so it looks
like the `snapd` daemon
has an off-by-one error in the statedump.)

Thanks,
Riccardo


glusterdump.1726.dump.1532446976.gz
Description: application/gzip


run-gluster-snaps-39f9f186c67f418a989f783c3289d166-brick3.5446.dump.1532446840.gz
Description: application/gzip


napd-glusterfs.5482.dump.1532446843.gz
Description: application/gzip
___
Gluster-users mailing list
Gluster-users@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-users

Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-24 Thread Rafi Kavungal Chundattu Parambil
Let me try out the reproducible. By the time, can you try taking statedump of 
the client process, snapd process, snapshot brick process. Please refer to 
documentation [1] in case if you have any trouble in performing statedump 
operation.

[1] : https://docs.gluster.org/en/v3/Troubleshooting/statedump/

Rafi KC

- Original Message -
From: "Riccardo Murri" 
To: "Mohammed Rafi K C" 
Cc: gluster-users@gluster.org
Sent: Tuesday, July 24, 2018 6:42:44 PM
Subject: Re: [Gluster-users] Cannot list `.snaps/` directory

Hello,

I have set up a test cluster with GlusterFS 4.1 and Ubuntu 16.04.5 and
I get the same behavior:
`ls .snaps/test/` hangs indefinitely in a getdents() system call.  I
can mount and list the snapshot
just fine with `mount -t glusterfs`, it's just the USS feature that is
not working.

Is this a known bug?  Any hints on how to work it around?

Thanks,
Riccardo
___
Gluster-users mailing list
Gluster-users@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-users


Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-24 Thread Riccardo Murri
Hello,

I have set up a test cluster with GlusterFS 4.1 and Ubuntu 16.04.5 and
I get the same behavior:
`ls .snaps/test/` hangs indefinitely in a getdents() system call.  I
can mount and list the snapshot
just fine with `mount -t glusterfs`, it's just the USS feature that is
not working.

Is this a known bug?  Any hints on how to work it around?

Thanks,
Riccardo
___
Gluster-users mailing list
Gluster-users@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-users


Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-19 Thread Riccardo Murri
Re-sending the log files as attachments, to avoid MUAs corrupting them...

Ciao,
R
### client logs:

[2018-07-19 13:30:10.206657] I [glusterfsd-mgmt.c:52:mgmt_cbk_spec] 0-mgmt: 
Volume file changed
[2018-07-19 13:30:10.316710] I [MSGID: 114007] 
[client.c:2402:client_check_remote_host] 0-glusterfs-snapd-client: Remote host 
is not set. Assuming the volfile server as remote host [Invalid argument]
[2018-07-19 13:30:10.316910] D [io-stats.c:3870:reconfigure] 0-glusterfs: 
reconfigure returning 0
[2018-07-19 13:30:10.316969] D [glusterfsd-mgmt.c:1920:mgmt_getspec_cbk] 
0-glusterfsd-mgmt: No need to re-load volfile, reconfigure done
[2018-07-19 13:30:31.823912] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: STAT scheduled as fast fop
[2018-07-19 13:30:31.837598] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: FLUSH scheduled as normal fop
[2018-07-19 13:30:33.174222] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: LOOKUP scheduled as fast fop
[2018-07-19 13:30:33.175564] D [MSGID: 0] 
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate lookup of 
/opt returned with op_ret 0
[2018-07-19 13:30:35.546485] D [logging.c:1979:_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] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: STAT scheduled as fast fop" repeated 3 times between 
[2018-07-19 13:30:31.823912] and [2018-07-19 13:30:35.540106]
[2018-07-19 13:30:35.546479] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: OPENDIR scheduled as fast fop
[2018-07-19 13:30:35.548707] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:35.562717] D [logging.c:1979:_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
[2018-07-19 13:30:35.562298] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:35.562713] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: STAT scheduled as fast fop
[2018-07-19 13:30:35.562919] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: OPENDIR scheduled as fast fop
[2018-07-19 13:30:35.564746] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:35.574831] D [logging.c:1979:_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
[2018-07-19 13:30:35.570561] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:35.574827] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: STAT scheduled as fast fop
[2018-07-19 13:30:35.575078] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: OPENDIR scheduled as fast fop
[2018-07-19 13:30:35.576864] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:37.546586] D [logging.c:1855:gf_log_flush_timeout_cbk] 
0-logging-infra: Log timer timed out. About to flush outstanding messages if 
present
The message "D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: FLUSH scheduled as normal fop" repeated 2 times between 
[2018-07-19 13:30:31.837598] and [2018-07-19 13:30:31.838077]
The message "D [MSGID: 0] [dht-common.c:1056:dht_revalidate_cbk] 
0-glusterfs-dht: revalidate lookup of /opt returned with op_ret 0" repeated 4 
times between [2018-07-19 13:30:33.175564] and [2018-07-19 13:30:33.176783]
[2018-07-19 13:30:35.582728] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:37.546747] D [logging.c:1817:__gf_log_inject_timer_event] 
0-logging-infra: Starting timer now. Timeout = 120, current buf size = 5
[2018-07-19 13:30:38.647775] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: STAT scheduled as fast fop
[2018-07-19 13:30:38.650530] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: OPENDIR scheduled as fast fop
[2018-07-19 13:30:38.653807] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: READDIRP scheduled as fast fop
[2018-07-19 13:30:38.678216] D [MSGID: 0] [io-threads.c:358:iot_schedule] 
0-glusterfs-io-threads: LOOKUP scheduled as fast fop
[2018-07-19 13:30:38.680700] D 
[rpc-clnt-ping.c:99:rpc_clnt_remove_ping_timer_locked] (--> 
/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(_gf_log_callingfn+0x13b)[0x7f396011b4bb]
 (--> 
/usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_remove_ping_timer_locked+0x84)[0x7f395feec524]
 (--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(+0x12c4d)[0x7f395feecc4d] (--> 

Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-19 Thread Riccardo Murri
Hello Rafi,

many thanks for your prompt reply.

I have now tried to do:

   ls /data/opt/.snaps/test_*/

which hung and I interrupted it with Ctrl+C a few moments later.
I attach below the DEBUG-level logs of 1 brick and the client.

When should I take the statedump and how do I send them?

Thanks,
Riccardo


### client logs:

[2018-07-19 13:30:10.206657] I [glusterfsd-mgmt.c:52:mgmt_cbk_spec]
0-mgmt: Volume file changed
[2018-07-19 13:30:10.316710] I [MSGID: 114007]
[client.c:2402:client_check_remote_host] 0-glusterfs-snapd-client:
Remote host is not set. Assuming the volfile server as remote host
[Invalid argument]
[2018-07-19 13:30:10.316910] D [io-stats.c:3870:reconfigure]
0-glusterfs: reconfigure returning 0
[2018-07-19 13:30:10.316969] D
[glusterfsd-mgmt.c:1920:mgmt_getspec_cbk] 0-glusterfsd-mgmt: No need
to re-load volfile, reconfigure done
[2018-07-19 13:30:31.823912] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:31.837598] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: FLUSH
scheduled as normal fop
[2018-07-19 13:30:33.174222] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:30:33.175564] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt returned with op_ret 0
[2018-07-19 13:30:35.546485] D [logging.c:1979:_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] [io-threads.c:358:iot_schedule]
0-glusterfs-io-threads: STAT scheduled as fast fop" repeated 3 times
between [2018-07-19 13:30:31.823912] and [2018-07-19 13:30:35.540106]
[2018-07-19 13:30:35.546479] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:35.548707] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.562717] D [logging.c:1979:_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
[2018-07-19 13:30:35.562298] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.562713] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:35.562919] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:35.564746] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.574831] D [logging.c:1979:_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
[2018-07-19 13:30:35.570561] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.574827] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:35.575078] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:35.576864] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:37.546586] D
[logging.c:1855:gf_log_flush_timeout_cbk] 0-logging-infra: Log timer
timed out. About to flush outstanding messages if present
The message "D [MSGID: 0] [io-threads.c:358:iot_schedule]
0-glusterfs-io-threads: FLUSH scheduled as normal fop" repeated 2
times between [2018-07-19 13:30:31.837598] and [2018-07-19
13:30:31.838077]
The message "D [MSGID: 0] [dht-common.c:1056:dht_revalidate_cbk]
0-glusterfs-dht: revalidate lookup of /opt returned with op_ret 0"
repeated 4 times between [2018-07-19 13:30:33.175564] and [2018-07-19
13:30:33.176783]
[2018-07-19 13:30:35.582728] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:37.546747] D
[logging.c:1817:__gf_log_inject_timer_event] 0-logging-infra: Starting
timer now. Timeout = 120, current buf size = 5
[2018-07-19 13:30:38.647775] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:38.650530] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:38.653807] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:38.678216] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:30:38.680700] D
[rpc-clnt-ping.c:99:rpc_clnt_remove_ping_timer_locked] (-->
/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(_gf_log_callingfn+0x13b)[0x7f396011b4bb]
(--> 

Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-19 Thread Mohammed Rafi K C



On 07/19/2018 06:35 PM, Riccardo Murri wrote:
> Hello Rafi,
>
> mounting as a regular volume works fine:
>
> ubuntu@slurm-master-001:/var/log/glusterfs$ sudo mount -t glusterfs
> glusterfs-server-001:/snaps/test_GMT-2018.07.18-10.02.05/glusterfs
> /mnt
>
> ubuntu@slurm-master-001:/var/log/glusterfs$ ls /mnt/
> active  filesystem  homes  jobdaemon  opt  share
>
> ubuntu@slurm-master-001:/var/log/glusterfs$ ls /mnt/opt
> Anaconda2-5.1.0-Linux-x86_64  bin  lmod  modulefiles
>
> Any hint why it should not work via USS?
Let's figure it out :).

Can you enable debug log for both client and brick. Also can you take
statedump of client process and brick process

Regards
Rafi KC


>
> Thanks,
> R

___
Gluster-users mailing list
Gluster-users@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-users


Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-19 Thread Riccardo Murri
Hello Rafi,

mounting as a regular volume works fine:

ubuntu@slurm-master-001:/var/log/glusterfs$ sudo mount -t glusterfs
glusterfs-server-001:/snaps/test_GMT-2018.07.18-10.02.05/glusterfs
/mnt

ubuntu@slurm-master-001:/var/log/glusterfs$ ls /mnt/
active  filesystem  homes  jobdaemon  opt  share

ubuntu@slurm-master-001:/var/log/glusterfs$ ls /mnt/opt
Anaconda2-5.1.0-Linux-x86_64  bin  lmod  modulefiles

Any hint why it should not work via USS?

Thanks,
R
___
Gluster-users mailing list
Gluster-users@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-users


Re: [Gluster-users] Cannot list `.snaps/` directory

2018-07-19 Thread Rafi Kavungal Chundattu Parambil
Can you try mounting snapshot just like we mount a regular volume? 
syntax mount -t glusterfs host1:/snaps// 

Regards
Rafi KC

- Original Message -
From: "Riccardo Murri" 
To: gluster-users@gluster.org
Sent: Wednesday, July 18, 2018 3:58:34 PM
Subject: [Gluster-users] Cannot list `.snaps/` directory

Hello,

I am trying the USS snapshots on an existing cluster (GlusterFS 3.12.9
on Ubuntu 16.04, installed from the DEB packages on GlusterFS.org).

I can successfully create a snapshot, and it is correctly listed under
the volume's `.snaps` directory everywhere; for example:

  $ stat .snaps/test_GMT-2018.07.18-10.02.05
  File: '.snaps/test_GMT-2018.07.18-10.02.05'
  Size: 4096Blocks: 8  IO Block: 131072 directory
  Device: 2bh/43d Inode: 11895042009497816687  Links: 6
  Access: (0755/drwxr-xr-x)  Uid: (0/root)   Gid: (0/root)
  Access: 2018-07-16 13:33:29.649519330 +
  Modify: 2018-07-16 13:33:29.548396587 +
  Change: 2018-07-16 13:33:29.645519332 +
  Birth: -

However running:

ls .snaps/test_GMT-2018.07.18-10.02.05/

just hangs forever.  Running the same command under `strace` shows
that it's stuck repeatedly just doing this `getdents system call::

getdents(3, [{d_ino=15424314298293051273,
d_off=9223372036854775805, d_reclen=32, d_name="modulefiles",
d_type=DT_DIR}, {d_ino=1, d_off=7346686173273481909, d_reclen=24,
d_name="..", d_type=DT_DIR}, {d_ino=13594788684206387598,
d_off=7356868894832018317, d_reclen=24, d_name=".", d_type=DT_DIR},
{d_ino=9350865815378619609, d_off=9223372036854775805, d_reclen=24,
d_name="bin", d_type=DT_DIR}], 131072) = 104

Looking in the server-side logs shows no issue (I am attaching the
last lines of logs and other config commands below).

What could be the problem here?

Thanks,
Riccardo

(Note for the logs: snap was created at 10:02 UTC.)

$ tail glusterd.log bricks/run-gluster-snaps*log snaps/glusterfs/snapd.log
[2018-07-18 10:02:07.183666] I
[glusterd-utils.c:6047:glusterd_brick_start] 0-management: starting a
fresh brick process for brick
/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
[2018-07-18 10:02:07.194801] I
[rpc-clnt.c:1044:rpc_clnt_connection_init] 0-management: setting
frame-timeout to 600
[2018-07-18 10:02:07.296262] I [socket.c:2474:socket_event_handler]
0-transport: EPOLLERR - disconnecting now
[2018-07-18 10:02:07.297582] I [MSGID: 106005]
[glusterd-handler.c:6071:__glusterd_brick_rpc_notify] 0-management:
Brick 
glusterfs-server-001:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
has disconnected from glusterd.
[2018-07-18 10:02:07.298327] W [MSGID: 106057]
[glusterd-snapshot-utils.c:410:glusterd_snap_volinfo_find]
0-management: Snap volume
2bd07d5165de4277be94d3bc2b4a6ff4.glusterfs-server-001.run-gluster-snaps-2bd07d5165de4277be94d3bc2b4a6ff4-brick4
not found [Invalid argument]
[2018-07-18 10:02:07.587928] I [MSGID: 106143]
[glusterd-pmap.c:295:pmap_registry_bind] 0-pmap: adding brick
/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4 on port
49154

==> bricks/run-gluster-snaps-2bd07d5165de4277be94d3bc2b4a6ff4-brick4.log <==
166: option transport.socket.keepalive-interval 2
167: option transport.socket.keepalive-count 9
168: option transport.listen-backlog 10
169: subvolumes /run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
170: end-volume
171:
+--+
[2018-07-18 10:02:50.156027] I [addr.c:55:compare_addr_and_update]
0-/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4: allowed
= "*", received addr = "172.23.62.200"
[2018-07-18 10:02:50.156366] I [login.c:111:gf_auth] 0-auth/login:
allowed user names: f75e457a-7898-4863-9754-2209ddf47573
[2018-07-18 10:02:50.156402] I [MSGID: 115029]
[server-handshake.c:793:server_setvolume]
0-2bd07d5165de4277be94d3bc2b4a6ff4-server: accepted client from
glusterfs-server-005-16843-2018/07/18-10:02:50:142015-glusterfs-client-12-0-0
(version: 3.12.9)

==> snaps/glusterfs/snapd.log <==
[2018-07-18 08:27:43.710242] I [addr.c:55:compare_addr_and_update]
0-snapd-glusterfs: allowed = "*", received addr = "172.23.62.189"
[2018-07-18 08:27:43.710291] I [MSGID: 115029]
[server-handshake.c:793:server_setvolume] 0-glusterfs-server: accepted
client from 
slurm-master-001-28933-2018/06/11-14:28:30:530655-glusterfs-snapd-client-45-0
(version: 3.12.9)
[2018-07-18 08:27:43.713616] E
[server-handshake.c:385:server_first_lookup] 0-snapd-glusterfs: lookup
on root failed: Success
[2018-07-18 08:27:43.729767] I [addr.c:55:compare_addr_and_update]
0-snapd-glusterfs: allowed = "*", received addr = "172.23.62.189"
[2018-07-18 08:27:43.729809] I [MSGID: 115029]
[server-handshake.c:793:server_setvolume] 0-glusterfs-server: accepted
client from 
slurm-master-001-9204-2018/07/10-12:11:24:974712-glusterfs-snapd-client-18-0
(vers

[Gluster-users] Cannot list `.snaps/` directory

2018-07-18 Thread Riccardo Murri
Hello,

I am trying the USS snapshots on an existing cluster (GlusterFS 3.12.9
on Ubuntu 16.04, installed from the DEB packages on GlusterFS.org).

I can successfully create a snapshot, and it is correctly listed under
the volume's `.snaps` directory everywhere; for example:

  $ stat .snaps/test_GMT-2018.07.18-10.02.05
  File: '.snaps/test_GMT-2018.07.18-10.02.05'
  Size: 4096Blocks: 8  IO Block: 131072 directory
  Device: 2bh/43d Inode: 11895042009497816687  Links: 6
  Access: (0755/drwxr-xr-x)  Uid: (0/root)   Gid: (0/root)
  Access: 2018-07-16 13:33:29.649519330 +
  Modify: 2018-07-16 13:33:29.548396587 +
  Change: 2018-07-16 13:33:29.645519332 +
  Birth: -

However running:

ls .snaps/test_GMT-2018.07.18-10.02.05/

just hangs forever.  Running the same command under `strace` shows
that it's stuck repeatedly just doing this `getdents system call::

getdents(3, [{d_ino=15424314298293051273,
d_off=9223372036854775805, d_reclen=32, d_name="modulefiles",
d_type=DT_DIR}, {d_ino=1, d_off=7346686173273481909, d_reclen=24,
d_name="..", d_type=DT_DIR}, {d_ino=13594788684206387598,
d_off=7356868894832018317, d_reclen=24, d_name=".", d_type=DT_DIR},
{d_ino=9350865815378619609, d_off=9223372036854775805, d_reclen=24,
d_name="bin", d_type=DT_DIR}], 131072) = 104

Looking in the server-side logs shows no issue (I am attaching the
last lines of logs and other config commands below).

What could be the problem here?

Thanks,
Riccardo

(Note for the logs: snap was created at 10:02 UTC.)

$ tail glusterd.log bricks/run-gluster-snaps*log snaps/glusterfs/snapd.log
[2018-07-18 10:02:07.183666] I
[glusterd-utils.c:6047:glusterd_brick_start] 0-management: starting a
fresh brick process for brick
/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
[2018-07-18 10:02:07.194801] I
[rpc-clnt.c:1044:rpc_clnt_connection_init] 0-management: setting
frame-timeout to 600
[2018-07-18 10:02:07.296262] I [socket.c:2474:socket_event_handler]
0-transport: EPOLLERR - disconnecting now
[2018-07-18 10:02:07.297582] I [MSGID: 106005]
[glusterd-handler.c:6071:__glusterd_brick_rpc_notify] 0-management:
Brick 
glusterfs-server-001:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
has disconnected from glusterd.
[2018-07-18 10:02:07.298327] W [MSGID: 106057]
[glusterd-snapshot-utils.c:410:glusterd_snap_volinfo_find]
0-management: Snap volume
2bd07d5165de4277be94d3bc2b4a6ff4.glusterfs-server-001.run-gluster-snaps-2bd07d5165de4277be94d3bc2b4a6ff4-brick4
not found [Invalid argument]
[2018-07-18 10:02:07.587928] I [MSGID: 106143]
[glusterd-pmap.c:295:pmap_registry_bind] 0-pmap: adding brick
/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4 on port
49154

==> bricks/run-gluster-snaps-2bd07d5165de4277be94d3bc2b4a6ff4-brick4.log <==
166: option transport.socket.keepalive-interval 2
167: option transport.socket.keepalive-count 9
168: option transport.listen-backlog 10
169: subvolumes /run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
170: end-volume
171:
+--+
[2018-07-18 10:02:50.156027] I [addr.c:55:compare_addr_and_update]
0-/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4: allowed
= "*", received addr = "172.23.62.200"
[2018-07-18 10:02:50.156366] I [login.c:111:gf_auth] 0-auth/login:
allowed user names: f75e457a-7898-4863-9754-2209ddf47573
[2018-07-18 10:02:50.156402] I [MSGID: 115029]
[server-handshake.c:793:server_setvolume]
0-2bd07d5165de4277be94d3bc2b4a6ff4-server: accepted client from
glusterfs-server-005-16843-2018/07/18-10:02:50:142015-glusterfs-client-12-0-0
(version: 3.12.9)

==> snaps/glusterfs/snapd.log <==
[2018-07-18 08:27:43.710242] I [addr.c:55:compare_addr_and_update]
0-snapd-glusterfs: allowed = "*", received addr = "172.23.62.189"
[2018-07-18 08:27:43.710291] I [MSGID: 115029]
[server-handshake.c:793:server_setvolume] 0-glusterfs-server: accepted
client from 
slurm-master-001-28933-2018/06/11-14:28:30:530655-glusterfs-snapd-client-45-0
(version: 3.12.9)
[2018-07-18 08:27:43.713616] E
[server-handshake.c:385:server_first_lookup] 0-snapd-glusterfs: lookup
on root failed: Success
[2018-07-18 08:27:43.729767] I [addr.c:55:compare_addr_and_update]
0-snapd-glusterfs: allowed = "*", received addr = "172.23.62.189"
[2018-07-18 08:27:43.729809] I [MSGID: 115029]
[server-handshake.c:793:server_setvolume] 0-glusterfs-server: accepted
client from 
slurm-master-001-9204-2018/07/10-12:11:24:974712-glusterfs-snapd-client-18-0
(version: 3.12.9)
[2018-07-18 08:27:43.730260] E
[server-handshake.c:385:server_first_lookup] 0-snapd-glusterfs: lookup
on root failed: Success
[2018-07-18 08:28:49.401381] I
[snapview-server-mgmt.c:22:mgmt_cbk_snap] 0-mgmt: list of snapshots
changed
[2018-07-18 09:57:29.838877] I
[snapview-server-mgmt.c:22:mgmt_cbk_snap] 0-mgmt: list of snapshots
changed
[2018-07-18 09:58:28.026000] I
[snapview-server-mgmt.c:22:mgmt_cbk_snap] 0-mgmt: