Discussion:
[Gluster-users] Cannot list `.snaps/<snapname>` directory
Riccardo Murri
2018-07-18 10:28:34 UTC
Permalink
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: 4096 Blocks: 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 +0000
Modify: 2018-07-16 13:33:29.548396587 +0000
Change: 2018-07-16 13:33:29.645519332 +0000
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: list of snapshots
changed
[2018-07-18 10:02:11.611279] I
[snapview-server-mgmt.c:22:mgmt_cbk_snap] 0-mgmt: list of snapshots
changed

$ pdsh -g glusterfs_server 'sudo lvs' | dshbak -c
----------------
glusterfs-server-001
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 32.30
glusterfs data twi-aot--- 4.88t
26.48 13.65
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
32.30
----------------
glusterfs-server-002
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 32.28
glusterfs data twi-aot--- 4.88t
26.46 13.66
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
32.28
----------------
glusterfs-server-003
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 57.46
glusterfs data twi-aot--- 4.88t
47.10 23.88
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
57.46
----------------
glusterfs-server-004
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 46.72
glusterfs data twi-aot--- 4.88t
38.30 19.53
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
46.72
----------------
glusterfs-server-005
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 65.51
glusterfs data twi---t--- 4.88t
53.70 27.20
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
65.51

$ sudo gluster peer status
Number of Peers: 4

Hostname: glusterfs-server-005
Uuid: d53398f6-19d4-4633-8bc3-e493dac41789
State: Peer in Cluster (Connected)

Hostname: glusterfs-server-004
Uuid: 9a5763d2-1941-4e5d-8d33-8d6756f7f318
State: Peer in Cluster (Connected)

Hostname: glusterfs-server-003
Uuid: 3c74d2b4-a4f3-42d4-9511-f6174b0a641d
State: Peer in Cluster (Connected)

Hostname: glusterfs-server-002
Uuid: 5951cff1-2155-40b0-a94f-84ff2e4aa7c6
State: Peer in Cluster (Connected)

$ sudo gluster volume status
Status of volume: glusterfs
Gluster process TCP Port RDMA Port Online Pid
------------------------------------------------------------------------------
Brick glusterfs-server-005:/s
rv/glusterfs 49152 0 Y 12007
Brick glusterfs-server-004:/s
rv/glusterfs 49152 0 Y 14713
Brick glusterfs-server-003:/s
rv/glusterfs 49152 0 Y 14993
Brick glusterfs-server-001:/s
rv/glusterfs 49152 0 Y 20735
Brick glusterfs-server-002:/s
rv/glusterfs 49152 0 Y 19967
Snapshot Daemon on localhost 49153 0 Y 28323
Snapshot Daemon on glusterfs-
server-004 49153 0 Y 21229
Snapshot Daemon on glusterfs-
server-005 49153 0 Y 16843
Snapshot Daemon on glusterfs-
server-003 49153 0 Y 20673
Snapshot Daemon on glusterfs-
server-002 49153 0 Y 21441

Task Status of Volume glusterfs
------------------------------------------------------------------------------
Task : Rebalance
ID : 0eaf6ad1-df95-48f4-b941-17488010ddcc
Status : completed

$ sudo gluster snapshot status

Snap Name : test_GMT-2018.07.18-10.02.05
Snap UUID : 1b63ce46-334d-4faf-9081-a5b68d415786

Brick Path :
glusterfs-server-005:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick1
Volume Group : data
Brick Running : Yes
Brick PID : 17074
Data Percentage : 65.51
LV Size : 4.00t


Brick Path :
glusterfs-server-004:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick2
Volume Group : data
Brick Running : Yes
Brick PID : 21452
Data Percentage : 46.72
LV Size : 4.00t


Brick Path :
glusterfs-server-003:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick3
Volume Group : data
Brick Running : Yes
Brick PID : 20881
Data Percentage : 57.46
LV Size : 4.00t


Brick Path :
glusterfs-server-001:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
Volume Group : data
Brick Running : Yes
Brick PID : 28925
Data Percentage : 32.30
LV Size : 4.00t


Brick Path :
glusterfs-server-002:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick5
Volume Group : data
Brick Running : Yes
Brick PID : 21746
Data Percentage : 32.28
LV Size : 4.00t
Rafi Kavungal Chundattu Parambil
2018-07-19 12:55:59 UTC
Permalink
Can you try mounting snapshot just like we mount a regular volume?
syntax mount -t glusterfs host1:/snaps/<snap name>/<volname> <mount point>

Regards
Rafi KC

----- Original Message -----
From: "Riccardo Murri" <***@gmail.com>
To: gluster-***@gluster.org
Sent: Wednesday, July 18, 2018 3:58:34 PM
Subject: [Gluster-users] Cannot list `.snaps/<snapname>` 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: 4096 Blocks: 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 +0000
Modify: 2018-07-16 13:33:29.548396587 +0000
Change: 2018-07-16 13:33:29.645519332 +0000
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: list of snapshots
changed
[2018-07-18 10:02:11.611279] I
[snapview-server-mgmt.c:22:mgmt_cbk_snap] 0-mgmt: list of snapshots
changed

$ pdsh -g glusterfs_server 'sudo lvs' | dshbak -c
----------------
glusterfs-server-001
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 32.30
glusterfs data twi-aot--- 4.88t
26.48 13.65
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
32.30
----------------
glusterfs-server-002
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 32.28
glusterfs data twi-aot--- 4.88t
26.46 13.66
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
32.28
----------------
glusterfs-server-003
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 57.46
glusterfs data twi-aot--- 4.88t
47.10 23.88
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
57.46
----------------
glusterfs-server-004
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 46.72
glusterfs data twi-aot--- 4.88t
38.30 19.53
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
46.72
----------------
glusterfs-server-005
----------------
LV VG Attr LSize Pool
Origin Data% Meta% Move Log Cpy%Sync Convert
2bd07d5165de4277be94d3bc2b4a6ff4_0 data Vwi-aot--- 4.00t glusterfs
srv_glusterfs 65.51
glusterfs data twi---t--- 4.88t
53.70 27.20
srv_glusterfs data Vwi-aot--- 4.00t glusterfs
65.51

$ sudo gluster peer status
Number of Peers: 4

Hostname: glusterfs-server-005
Uuid: d53398f6-19d4-4633-8bc3-e493dac41789
State: Peer in Cluster (Connected)

Hostname: glusterfs-server-004
Uuid: 9a5763d2-1941-4e5d-8d33-8d6756f7f318
State: Peer in Cluster (Connected)

Hostname: glusterfs-server-003
Uuid: 3c74d2b4-a4f3-42d4-9511-f6174b0a641d
State: Peer in Cluster (Connected)

Hostname: glusterfs-server-002
Uuid: 5951cff1-2155-40b0-a94f-84ff2e4aa7c6
State: Peer in Cluster (Connected)

$ sudo gluster volume status
Status of volume: glusterfs
Gluster process TCP Port RDMA Port Online Pid
------------------------------------------------------------------------------
Brick glusterfs-server-005:/s
rv/glusterfs 49152 0 Y 12007
Brick glusterfs-server-004:/s
rv/glusterfs 49152 0 Y 14713
Brick glusterfs-server-003:/s
rv/glusterfs 49152 0 Y 14993
Brick glusterfs-server-001:/s
rv/glusterfs 49152 0 Y 20735
Brick glusterfs-server-002:/s
rv/glusterfs 49152 0 Y 19967
Snapshot Daemon on localhost 49153 0 Y 28323
Snapshot Daemon on glusterfs-
server-004 49153 0 Y 21229
Snapshot Daemon on glusterfs-
server-005 49153 0 Y 16843
Snapshot Daemon on glusterfs-
server-003 49153 0 Y 20673
Snapshot Daemon on glusterfs-
server-002 49153 0 Y 21441

Task Status of Volume glusterfs
------------------------------------------------------------------------------
Task : Rebalance
ID : 0eaf6ad1-df95-48f4-b941-17488010ddcc
Status : completed

$ sudo gluster snapshot status

Snap Name : test_GMT-2018.07.18-10.02.05
Snap UUID : 1b63ce46-334d-4faf-9081-a5b68d415786

Brick Path :
glusterfs-server-005:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick1
Volume Group : data
Brick Running : Yes
Brick PID : 17074
Data Percentage : 65.51
LV Size : 4.00t


Brick Path :
glusterfs-server-004:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick2
Volume Group : data
Brick Running : Yes
Brick PID : 21452
Data Percentage : 46.72
LV Size : 4.00t


Brick Path :
glusterfs-server-003:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick3
Volume Group : data
Brick Running : Yes
Brick PID : 20881
Data Percentage : 57.46
LV Size : 4.00t


Brick Path :
glusterfs-server-001:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick4
Volume Group : data
Brick Running : Yes
Brick PID : 28925
Data Percentage : 32.30
LV Size : 4.00t


Brick Path :
glusterfs-server-002:/run/gluster/snaps/2bd07d5165de4277be94d3bc2b4a6ff4/brick5
Volume Group : data
Brick Running : Yes
Brick PID : 21746
Data Percentage : 32.28
LV Size : 4.00t
Riccardo Murri
2018-07-19 13:05:20 UTC
Permalink
Hello Rafi,

mounting as a regular volume works fine:

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

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

***@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
Mohammed Rafi K C
2018-07-19 13:23:12 UTC
Permalink
Post by Riccardo Murri
Hello Rafi,
glusterfs-server-001:/snaps/test_GMT-2018.07.18-10.02.05/glusterfs
/mnt
active filesystem homes jobdaemon opt share
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
Post by Riccardo Murri
Thanks,
R
Riccardo Murri
2018-07-19 13:40:36 UTC
Permalink
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]
(--> /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]
(--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_submit+0x416)[0x7f395fee9ad6]
(--> /usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/client.so(+0xf45e)[0x7f3959ff345e]
))))) 0-: 172.23.62.200:49153: ping timer event already removed
[2018-07-19 13:30:38.681239] D [rpc-clnt-ping.c:211:rpc_clnt_ping_cbk]
0-glusterfs-snapd-client: Ping latency is 0ms
[2018-07-19 13:30:44.547902] D
[rpc-clnt-ping.c:336:rpc_clnt_start_ping] 0-glusterfs-client-10:
returning as transport is already disconnected OR there are no frames
(0 || 0)
[2018-07-19 13:30:44.548027] D
[rpc-clnt-ping.c:336:rpc_clnt_start_ping] 0-glusterfs-client-12:
returning as transport is already disconnected OR there are no frames
(0 || 0)
[2018-07-19 13:30:44.548042] D
[rpc-clnt-ping.c:336:rpc_clnt_start_ping] 0-glusterfs-client-13:
returning as transport is already disconnected OR there are no frames
(0 || 0)
[2018-07-19 13:30:44.548053] D
[rpc-clnt-ping.c:336:rpc_clnt_start_ping] 0-glusterfs-client-8:
returning as transport is already disconnected OR there are no frames
(0 || 0)
[2018-07-19 13:30:44.548065] D
[rpc-clnt-ping.c:336:rpc_clnt_start_ping] 0-glusterfs-client-9:
returning as transport is already disconnected OR there are no frames
(0 || 0)
[2018-07-19 13:31:01.189801] 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]
(--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_submit+0x416)[0x7f395fee9ad6]
(--> /usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/client.so(+0xf45e)[0x7f3959ff345e]
))))) 0-: 172.23.62.196:49152: ping timer event already removed
[2018-07-19 13:31:01.190172] 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]
(--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_submit+0x416)[0x7f395fee9ad6]
(--> /usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/client.so(+0xf45e)[0x7f3959ff345e]
))))) 0-: 172.23.62.200:49152: ping timer event already removed
[2018-07-19 13:31:01.190441] 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]
(--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_submit+0x416)[0x7f395fee9ad6]
(--> /usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/client.so(+0xf45e)[0x7f3959ff345e]
))))) 0-: 172.23.62.197:49152: ping timer event already removed
[2018-07-19 13:31:01.190697] 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]
(--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_submit+0x416)[0x7f395fee9ad6]
(--> /usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/client.so(+0xf45e)[0x7f3959ff345e]
))))) 0-: 172.23.62.199:49152: ping timer event already removed
[2018-07-19 13:31:01.190973] 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]
(--> /usr/lib/x86_64-linux-gnu/libgfrpc.so.0(rpc_clnt_submit+0x416)[0x7f395fee9ad6]
(--> /usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/client.so(+0xf45e)[0x7f3959ff345e]
))))) 0-: 172.23.62.198:49152: ping timer event already removed
[2018-07-19 13:31:01.191210] D [rpc-clnt-ping.c:211:rpc_clnt_ping_cbk]
0-glusterfs-client-8: Ping latency is 1ms
[2018-07-19 13:31:01.191336] D [rpc-clnt-ping.c:211:rpc_clnt_ping_cbk]
0-glusterfs-client-13: Ping latency is 0ms
[2018-07-19 13:31:01.191558] D [rpc-clnt-ping.c:211:rpc_clnt_ping_cbk]
0-glusterfs-client-12: Ping latency is 1ms
[2018-07-19 13:31:01.191626] D [rpc-clnt-ping.c:211:rpc_clnt_ping_cbk]
0-glusterfs-client-9: Ping latency is 0ms
[2018-07-19 13:31:01.191657] D [rpc-clnt-ping.c:211:rpc_clnt_ping_cbk]
0-glusterfs-client-10: Ping latency is 0ms
[2018-07-19 13:31:01.193908] 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:31:01.197302] 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: LOOKUP scheduled as fast fop" repeated 2 times
between [2018-07-19 13:30:38.678216] and [2018-07-19 13:31:01.196236]
[2018-07-19 13:31:01.197299] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt/lmod returned with op_ret 0
[2018-07-19 13:31:01.201816] 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] [dht-common.c:1056:dht_revalidate_cbk]
0-glusterfs-dht: revalidate lookup of /opt/lmod returned with op_ret
0" repeated 4 times between [2018-07-19 13:31:01.197299] and
[2018-07-19 13:31:01.198446]
[2018-07-19 13:31:01.201812] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:31:01.202137] D [MSGID: 0]
[dht-common.c:2694:dht_lookup] 0-glusterfs-dht: calling revalidate
lookup for /opt/lmod/lmod at glusterfs-client-9
[2018-07-19 13:31:01.203034] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt/lmod/lmod returned with op_ret 0
[2018-07-19 13:31:01.203243] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READLINK
scheduled as fast fop
[2018-07-19 13:31:01.204160] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:31:01.204997] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt/lmod/7.0 returned with op_ret 0
[2018-07-19 13:31:01.206434] 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] [dht-common.c:1056:dht_revalidate_cbk]
0-glusterfs-dht: revalidate lookup of /opt/lmod/7.0 returned with
op_ret 0" repeated 4 times between [2018-07-19 13:31:01.204997] and
[2018-07-19 13:31:01.206213]
[2018-07-19 13:31:01.206431] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:31:01.207314] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt/lmod/7.0/init returned with op_ret 0
[2018-07-19 13:31:01.210478] 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] [dht-common.c:1056:dht_revalidate_cbk]
0-glusterfs-dht: revalidate lookup of /opt/lmod/7.0/init returned with
op_ret 0" repeated 4 times between [2018-07-19 13:31:01.207314] and
[2018-07-19 13:31:01.210221]
[2018-07-19 13:31:01.210475] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:31:01.210647] D [MSGID: 0]
[dht-common.c:2694:dht_lookup] 0-glusterfs-dht: calling revalidate
lookup for /opt/lmod/7.0/init/bash at glusterfs-client-9
[2018-07-19 13:31:01.211394] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt/lmod/7.0/init/bash returned with op_ret 0
[2018-07-19 13:31:01.211590] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPEN scheduled
as fast fop
[2018-07-19 13:31:01.211961] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: FLUSH
scheduled as normal fop
[2018-07-19 13:31:01.217981] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READLINK
scheduled as fast fop
[2018-07-19 13:31:01.219091] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:31:01.219269] D [MSGID: 0]
[dht-common.c:2694:dht_lookup] 0-glusterfs-dht: calling revalidate
lookup for /opt/lmod/7.0/init/lmod_bash_completions at
glusterfs-client-9
[2018-07-19 13:31:01.220009] D [MSGID: 0]
[dht-common.c:1056:dht_revalidate_cbk] 0-glusterfs-dht: revalidate
lookup of /opt/lmod/7.0/init/lmod_bash_completions returned with
op_ret 0
[2018-07-19 13:31:01.913330] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: FLUSH
scheduled as normal fop


### brick 1 logs:

[2018-07-19 13:29:46.290627] D [MSGID: 0]
[options.c:1141:xlator_reconfigure_rec] 0-glusterfs-io-stats:
reconfigured
[2018-07-19 13:29:46.290642] D [MSGID: 0]
[options.c:1160:xlator_reconfigure_rec] 0-/srv/glusterfs: No
reconfigure() found
[2018-07-19 13:29:46.290685] D
[glusterfsd-mgmt.c:1920:mgmt_getspec_cbk] 0-glusterfsd-mgmt: No need
to re-load volfile, reconfigure done
[2018-07-19 13:30:01.770678] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287] -->/usr/li
b/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff]
) 0-client_t: slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:01.770776] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:01.771062] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955] -->/usr/
lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8
c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:10.062875] I [glusterfsd-mgmt.c:52:mgmt_cbk_spec]
0-mgmt: Volume file changed
[2018-07-19 13:30:10.062935] D
[rpc-clnt-ping.c:317:rpc_clnt_start_ping] 0-glusterfs: ping timeout is
0, returning
[2018-07-19 13:30:10.197421] I
[glusterfsd-mgmt.c:1888:mgmt_getspec_cbk] 0-glusterfs: No change in
volfile,continuing
[2018-07-19 13:30:31.824458] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287] -->/usr/li
b/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff]
) 0-client_t: slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:31.824855] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:31.846677] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:31.847060] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:33.172175] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:33.172544] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:33.174656] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:33.174787] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:30:33.175224] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.540359] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.540619] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.546862] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x25b67)
[0x7fe1eeaffb67]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.546923] 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 4 times
between [2018-07-19 13:30:01.770776] and [2018-07-19 13:30:35.540423]
[2018-07-19 13:30:35.546920] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:35.547607] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1baed)
[0x7fe1eeaf5aed]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.553814] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x27fe2)
[0x7fe1eeb01fe2]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.553856] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.554407] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x205d1)
[0x7fe1eeafa5d1]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.562703] D [MSGID: 0]
[posix-helpers.c:1466:posix_janitor_thread_proc] 0-glusterfs-posix:
janitor: closing dir fd=0x7fe1b465e7e0
[2018-07-19 13:30:35.563193] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x25b67)
[0x7fe1eeaffb67]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.563242] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:35.563528] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1baed)
[0x7fe1eeaf5aed]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.567429] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x27fe2)
[0x7fe1eeb01fe2]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.567477] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.567894] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x205d1)
[0x7fe1eeafa5d1]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.570973] D [MSGID: 0]
[posix-helpers.c:1466:posix_janitor_thread_proc] 0-glusterfs-posix:
janitor: closing dir fd=0x7fe1b465e7e0
[2018-07-19 13:30:35.575311] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x25b67)
[0x7fe1eeaffb67]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.575385] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:35.575610] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1baed)
[0x7fe1eeaf5aed]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.579637] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x27fe2)
[0x7fe1eeb01fe2]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:35.579677] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:35.580059] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x205d1)
[0x7fe1eeafa5d1]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:35.583122] D [MSGID: 0]
[posix-helpers.c:1466:posix_janitor_thread_proc] 0-glusterfs-posix:
janitor: closing dir fd=0x7fe1b465e7e0
[2018-07-19 13:30:38.648701] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:38.648855] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:38.649119] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:38.650779] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x25b67)
[0x7fe1eeaffb67]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:38.651968] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:38.652317] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1baed)
[0x7fe1eeaf5aed]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:38.656497] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x27fe2)
[0x7fe1eeb01fe2]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:38.656601] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:38.657507] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x205d1)
[0x7fe1eeafa5d1]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:38.660985] D [MSGID: 0]
[posix-helpers.c:1466:posix_janitor_thread_proc] 0-glusterfs-posix:
janitor: closing dir fd=0x7fe1bc8c1df0
[2018-07-19 13:30:38.662589] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x25b67)
[0x7fe1eeaffb67]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:38.662661] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: OPENDIR
scheduled as fast fop
[2018-07-19 13:30:38.662920] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1baed)
[0x7fe1eeaf5aed]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:38.666150] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x27fe2)
[0x7fe1eeb01fe2]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:38.666231] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: READDIRP
scheduled as fast fop
[2018-07-19 13:30:38.666714] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x205d1)
[0x7fe1eeafa5d1]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:30:38.669800] D [MSGID: 0]
[posix-helpers.c:1466:posix_janitor_thread_proc] 0-glusterfs-posix:
janitor: closing dir fd=0x7fe1bc8c1df0
[2018-07-19 13:30:38.677105] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:30:38.677185] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:30:38.677445] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:01.190565] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:01.191249] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:01.192975] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:01.193545] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:01.196731] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:01.197537] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:01.205377] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:01.205873] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:01.209143] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:01.209748] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:01.926270] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:01.926603] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:31:18.408919] 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: LOOKUP scheduled as fast fop" repeated 4 times
between [2018-07-19 13:30:33.174787] and [2018-07-19 13:31:01.209416]
The message "D [MSGID: 0] [io-threads.c:358:iot_schedule]
0-glusterfs-io-threads: STAT scheduled as fast fop" repeated 2 times
between [2018-07-19 13:30:38.677185] and [2018-07-19 13:31:01.926360]
[2018-07-19 13:31:18.409423] 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:31:32.006449] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:31:32.006595] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:31:32.006948] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:32:02.079972] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:32:02.080792] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:32:32.169915] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:32:32.171022] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:02.242813] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:02.243529] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:11.329101] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:11.329482] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:11.331254] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:11.331508] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: LOOKUP
scheduled as fast fop
[2018-07-19 13:33:11.333006] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:11.334574] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:11.335693] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:11.341771] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:11.342322] D [MSGID: 0] [posix.c:355:posix_lookup]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-posix returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:11.342574] D [MSGID: 0]
[changetimerecorder.c:309:ctr_lookup_cbk] 0-stack-trace:
stack-address: 0x7fe1d0dac0b0, glusterfs-changetimerecorder returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:11.342624] D [MSGID: 0]
[bit-rot-stub.c:2930:br_stub_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-bitrot-stub returned -1 error: No such file
or directory [No such file or directory]
[2018-07-19 13:33:11.342694] D [MSGID: 0]
[posix-acl.c:1017:posix_acl_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-access-control returned -1 error: No such
file or directory [No such file or directory]
[2018-07-19 13:33:11.342853] D [MSGID: 0] [posix.c:2639:pl_lookup_cbk]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-locks returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:11.342884] D [MSGID: 0] [upcall.c:796:up_lookup_cbk]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-upcall
returned -1 error: No such file or directory [No such file or
directory]
[2018-07-19 13:33:11.342932] D [MSGID: 0]
[defaults.c:1266:default_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-io-threads returned -1 error: No such file
or directory [No such file or directory]
[2018-07-19 13:33:11.342949] D [MSGID: 0]
[marker.c:2948:marker_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-marker returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:11.343041] D [MSGID: 0]
[defaults.c:1266:default_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-index returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:11.343062] D [MSGID: 0]
[io-stats.c:2214:io_stats_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-io-stats returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:11.343094] D [MSGID: 115050]
[server-rpc-fops.c:175:server_lookup_cbk] 0-glusterfs-server: 6700:
LOOKUP /opt/bin/ruptime
(65ce8807-e978-430c-821d-d83c8fb04d6c/ruptime), client:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0,
error-xlator: glusterfs-posix [No such file or directory]
[2018-07-19 13:33:11.343271] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:12.887244] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:12.887634] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:12.889028] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:12.889443] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:12.890704] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:12.891445] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:12.897167] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:12.897529] 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:33:12.897522] D [MSGID: 0]
[changetimerecorder.c:309:ctr_lookup_cbk] 0-stack-trace:
stack-address: 0x7fe1d0dac0b0, glusterfs-changetimerecorder returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:12.897528] D [MSGID: 0]
[bit-rot-stub.c:2930:br_stub_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-bitrot-stub returned -1 error: No such file
or directory [No such file or directory]
[2018-07-19 13:33:12.897644] D [MSGID: 0]
[posix-acl.c:1017:posix_acl_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-access-control returned -1 error: No such
file or directory [No such file or directory]
[2018-07-19 13:33:12.897673] D [MSGID: 0] [posix.c:2639:pl_lookup_cbk]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-locks returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:12.897703] D [MSGID: 0] [upcall.c:796:up_lookup_cbk]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-upcall
returned -1 error: No such file or directory [No such file or
directory]
[2018-07-19 13:33:12.897730] D [MSGID: 0]
[defaults.c:1266:default_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-io-threads returned -1 error: No such file
or directory [No such file or directory]
[2018-07-19 13:33:12.897763] D [MSGID: 0]
[marker.c:2948:marker_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-marker returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:12.897787] D [MSGID: 0]
[defaults.c:1266:default_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-index returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:12.897814] D [MSGID: 0]
[io-stats.c:2214:io_stats_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-io-stats returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:12.897844] D [MSGID: 115050]
[server-rpc-fops.c:175:server_lookup_cbk] 0-glusterfs-server: 6704:
LOOKUP /opt/bin/ruptime
(65ce8807-e978-430c-821d-d83c8fb04d6c/ruptime), client:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0,
error-xlator: glusterfs-posix [No such file or directory]
4d6c/ruptime), client:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0,
error-xlator: glusterfs-posix [No such file or directory]
[2018-07-19 13:33:12.897973] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:14.489599] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:14.489988] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:14.491647] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:14.492095] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:14.494026] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:14.494421] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:14.499289] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2e103)
[0x7fe1eeb08103]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:14.499587] 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] [posix.c:355:posix_lookup] 0-stack-trace:
stack-address: 0x7fe1d0dac0b0, glusterfs-posix returned -1 error: No
such file or directory [No such file or directory]" repeated 2 times
between [2018-07-19 13:33:11.342322] and [2018-07-19 13:33:14.499568]
[2018-07-19 13:33:14.499586] D [MSGID: 0]
[changetimerecorder.c:309:ctr_lookup_cbk] 0-stack-trace:
stack-address: 0x7fe1d0dac0b0, glusterfs-changetimerecorder returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:14.499694] D [MSGID: 0]
[bit-rot-stub.c:2930:br_stub_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-bitrot-stub returned -1 error: No such file
or directory [No such file or directory]
[2018-07-19 13:33:14.499722] D [MSGID: 0]
[posix-acl.c:1017:posix_acl_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-access-control returned -1 error: No such
file or directory [No such file or directory]
[2018-07-19 13:33:14.499756] D [MSGID: 0] [posix.c:2639:pl_lookup_cbk]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-locks returned
-1 error: No such file or directory [No such file or directory]
[2018-07-19 13:33:14.499779] D [MSGID: 0] [upcall.c:796:up_lookup_cbk]
0-stack-trace: stack-address: 0x7fe1d0dac0b0, glusterfs-upcall
returned -1 error: No such file or directory [No such file or
directory]
[2018-07-19 13:33:14.499834] D [MSGID: 0]
[defaults.c:1266:default_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-io-threads returned -1 error: No such file
or directory [No such file or directory]
[2018-07-19 13:33:14.499874] D [MSGID: 0]
[marker.c:2948:marker_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-marker returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:14.499903] D [MSGID: 0]
[defaults.c:1266:default_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-index returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:14.499928] D [MSGID: 0]
[io-stats.c:2214:io_stats_lookup_cbk] 0-stack-trace: stack-address:
0x7fe1d0dac0b0, glusterfs-io-stats returned -1 error: No such file or
directory [No such file or directory]
[2018-07-19 13:33:14.499965] D [MSGID: 115050]
[server-rpc-fops.c:175:server_lookup_cbk] 0-glusterfs-server: 6708:
LOOKUP /opt/bin/ruptime
(65ce8807-e978-430c-821d-d83c8fb04d6c/ruptime), client:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0,
error-xlator: glusterfs-posix [No such file or directory]
[2018-07-19 13:33:14.500134] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x2d814)
[0x7fe1eeb07814]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
[2018-07-19 13:33:18.426934] 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: STAT scheduled as fast fop" repeated 6 times
between [2018-07-19 13:31:32.006595] and [2018-07-19 13:33:14.489706]
The message "D [MSGID: 0] [io-threads.c:358:iot_schedule]
0-glusterfs-io-threads: LOOKUP scheduled as fast fop" repeated 8 times
between [2018-07-19 13:33:11.331508] and [2018-07-19 13:33:14.499450]
[2018-07-19 13:33:18.427036] 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:33:32.315885] D [client_t.c:331:gf_client_ref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x28287)
[0x7fe1eeb02287]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0xd37d)
[0x7fe1eeae737d]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_ref+0xbf)
[0x7fe1fbd4b6ff] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 2
[2018-07-19 13:33:32.316005] D [MSGID: 0]
[io-threads.c:358:iot_schedule] 0-glusterfs-io-threads: STAT scheduled
as fast fop
[2018-07-19 13:33:32.316627] D [client_t.c:440:gf_client_unref]
(-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x1f955)
[0x7fe1eeaf9955]
-->/usr/lib/x86_64-linux-gnu/glusterfs/3.12.9/xlator/protocol/server.so(+0x89f3)
[0x7fe1eeae29f3]
-->/usr/lib/x86_64-linux-gnu/libglusterfs.so.0(gf_client_unref+0x96)
[0x7fe1fbd4b8c6] ) 0-client_t:
slurm-master-001-19740-2018/07/18-09:48:19:570945-glusterfs-client-12-0-0:
ref-count 1
Riccardo Murri
2018-07-19 13:46:17 UTC
Permalink
Re-sending the log files as attachments, to avoid MUAs corrupting them...

Ciao,
R
Riccardo Murri
2018-07-24 13:12:44 UTC
Permalink
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
Rafi Kavungal Chundattu Parambil
2018-07-24 15:28:23 UTC
Permalink
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" <***@gmail.com>
To: "Mohammed Rafi K C" <***@redhat.com>
Cc: gluster-***@gluster.org
Sent: Tuesday, July 24, 2018 6:42:44 PM
Subject: Re: [Gluster-users] Cannot list `.snaps/<snapname>` 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
Riccardo Murri
2018-07-24 15:39:38 UTC
Permalink
Hello Rafi,

sorry I had taken the statedump of brick and client in the 3.12
cluster last week, but had forgotten to send them -- they're attached
to this email.

Thanks,
R
Riccardo Murri
2018-07-24 15:48:05 UTC
Permalink
...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

Loading...