search

gluster / glusterfs

Gluster Filesystem : Build your distributed storage in minutes
https://www.gluster.org
GNU General Public License v2.0
4.73k stars 1.08k forks source link

Geo-replication : "extended attribute not supported by the backend storage" in logs #3096

Closed FSangouard closed 2 years ago

FSangouard commented 2 years ago

Description of problem: After setting up a geo replication session, status command shows Active status, and everything seems to be ok, but we have the following message in the primary's logs in /var/log/glusterfs/geo-replication/volume1_<ip_primary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:

[2022-01-05 09:15:42.649444 +0000] E [fuse-bridge.c:4336:fuse_xattr_cbk] 0-glusterfs-fuse: extended attribute not supported by the backend storage

File systems are all XFS on both source cluster and target cluster. Both clusters are made up of 3 nodes, the source volume is a replicated volume with 3 replica, and we have one brick per node. Files are correctly replicated between clusters.

It looks like this is just a logging problem, but I would like to make sure of that.

The exact command to reproduce the issue: No specific command triggers this, but I created the session with:

gluster volume geo-replication volume1 georep@<ip_secondary1>::volume1 create push-pem

where volume1 is the name of both the source volume and the target volume, and georep is the unpriviledged user I created on the secondary nodes.

I followed https://docs.gluster.org/en/latest/Administrator-Guide/Geo-Replication/.

The full output of the command that failed: N/A

Expected results: No error message is logged when everything works

Mandatory info: - The output of the gluster volume info command:

gluster volume info

Volume Name: volume1
Type: Replicate
Volume ID: 31c7c970-41bd-4839-9da9-e29209b7ccf3
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x 3 = 3
Transport-type: tcp
Bricks:
Brick1: <primary1>:/applis/apsu/data/glusterfs/volume1/brick1/brick
Brick2: <primary2>:/applis/apsu/data/glusterfs/volume1/brick1/brick
Brick3: <primary3>:/applis/apsu/data/glusterfs/volume1/brick1/brick
Options Reconfigured:
changelog.changelog: on
geo-replication.ignore-pid-check: on
geo-replication.indexing: on
cluster.quorum-type: none
cluster.metadata-self-heal: on
cluster.entry-self-heal: on
storage.owner-uid: 2000
storage.owner-gid: 2000
cluster.data-self-heal: on
cluster.granular-entry-heal: on
storage.fips-mode-rchecksum: on
transport.address-family: inet
nfs.disable: on
performance.client-io-threads: off

Volume Name: volume2
Type: Replicate
Volume ID: 4601de2f-2045-4c7f-bf6a-f78573675ba8
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x 3 = 3
Transport-type: tcp
Bricks:
Brick1: <primary1>:/applis/apsu/data/glusterfs/volume2/brick1/brick
Brick2: <primary2>:/applis/apsu/data/glusterfs/volume2/brick1/brick
Brick3: <primary3>:/applis/apsu/data/glusterfs/volume2/brick1/brick
Options Reconfigured:
cluster.quorum-type: none
cluster.metadata-self-heal: on
cluster.entry-self-heal: on
storage.owner-uid: 2000
storage.owner-gid: 2000
cluster.data-self-heal: on
cluster.granular-entry-heal: on
storage.fips-mode-rchecksum: on
transport.address-family: inet
nfs.disable: on
performance.client-io-threads: off

- The output of the gluster volume status command:

gluster volume status
Status of volume: volume1
Gluster process                             TCP Port  RDMA Port  Online  Pid
------------------------------------------------------------------------------
Brick <primary1>:/applis/apsu/data/glusterfs/volume1/br
ick1/brick                                  49152     0          Y       1641
Brick <primary2>:/applis/apsu/data/glusterfs/volume1/br
ick1/brick                                  49152     0          Y       1122
Brick <primary3>:/applis/apsu/data/glusterfs/volume1/br
ick1/brick                                  49152     0          Y       22636
Self-heal Daemon on localhost               N/A       N/A        Y       1658
Self-heal Daemon on <primary2>                          N/A       N/A        Y       1139
Self-heal Daemon on <primary3>                          N/A       N/A        Y       22653

Task Status of Volume volume1
------------------------------------------------------------------------------
There are no active volume tasks

Status of volume: volume2
Gluster process                             TCP Port  RDMA Port  Online  Pid
------------------------------------------------------------------------------
Brick <primary1>:/applis/apsu/data/glusterfs/volume2/br
ick1/brick                                  49153     0          Y       2125
Brick <primary2>:/applis/apsu/data/glusterfs/volume2/br
ick1/brick                                  49153     0          Y       1402
Brick <primary3>:/applis/apsu/data/glusterfs/volume2/br
ick1/brick                                  49153     0          Y       22912
Self-heal Daemon on localhost               N/A       N/A        Y       1658
Self-heal Daemon on <primary2>                          N/A       N/A        Y       1139
Self-heal Daemon on <primary3>                          N/A       N/A        Y       22653

Task Status of Volume volume2
------------------------------------------------------------------------------
There are no active volume tasks

- The output of the gluster volume heal command:

gluster volume heal volume1 info
Brick <primary1>:/applis/apsu/data/glusterfs/volume1/brick1/brick
Status: Connected
Number of entries: 0

Brick <primary2>:/applis/apsu/data/glusterfs/volume1/brick1/brick
Status: Connected
Number of entries: 0

Brick <primary3>:/applis/apsu/data/glusterfs/volume1/brick1/brick
Status: Connected
Number of entries: 0

- Provide logs present on following locations of client and server nodes: I can provide debug logs from the primary's /var/log/glusterfs/geo-replication if needed.

- Is there any crash ? Provide the backtrace and coredump No crash

Additional info:

gluster volume geo-replication volume1 georep@<ip_secondary1>::volume1 status

MASTER NODE                                  MASTER VOL    MASTER BRICK                                        SLAVE USER    SLAVE                            SLAVE NODE    STATUS     CRAWL STATUS       LAST_SYNCED
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
<primary1>    volume1       /applis/apsu/data/glusterfs/volume1/brick1/brick    georep        georep@<ip_secondary1>::volume1                  Active     Changelog Crawl    2022-01-05 11:09:35
<primary2>    volume1       /applis/apsu/data/glusterfs/volume1/brick1/brick    georep        georep@<ip_secondary1>::volume1                  Passive    N/A                N/A
<primary3>    volume1       /applis/apsu/data/glusterfs/volume1/brick1/brick    georep        georep@<ip_secondary1>::volume1                  Passive    N/A                N/A

- The operating system / glusterfs version: CentOS 7.4 GlusterFS 9.4

Shwetha-Acharya commented 2 years ago

Could you please share the gsyncd and mnt logs @FSangouard

FSangouard commented 2 years ago

Here are the logs from the primary cluster's first node :

mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log gsyncd.log

Shwetha-Acharya commented 2 years ago

Thanks for the log, with the logs shared it is not evident who is sending the request for the xattr which is not supported by the backend storage.

Please enable debug log on geo-rep. And also grep for the time when xattr not supported error is occuring in /var/log/gluster directory. This should give some clue. @FSangouard

FSangouard commented 2 years ago

Well, after enabling debug on the geo-replication session, I don't get the error as often as before. Now it seems to appear only when I write something to the replicated volume on the source cluster. Since last time, I restarted the volumes and the replication session, so maybe that cleared up something.

Here are the debug logs from gsyncd at the time of the error:

gsyncd.log

And here are the grep results:

grep "extended attribute not supported by the backend storage" /var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log
[2022-01-13 15:37:22.207543 +0000] E [fuse-bridge.c:4336:fuse_xattr_cbk] 0-glusterfs-fuse: extended attribute not supported by the backend storage
grep -r "15:37:22" /var/log/glusterfs/                                                                                                                                      /var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.58602] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):556:crawlwrap] _GMaster: ... crawl #3694 done, took 5.007582 seconds
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.61188] I [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):1525:crawl] _GMaster: slave's time [{stime=(1641911058, 0)}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.70683] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):1509:changelogs_batch_process] _GMaster: processing changes [{batch=['/var/lib/misc/gluster/gsyncd/volume1_<ip_secondary1>_volume1/applis-apsu-data-glusterfs-volume1-brick1-brick/.processing/CHANGELOG.1642088236']}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.70807] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):1344:process] _GMaster: processing change [{changelog=/var/lib/misc/gluster/gsyncd/volume1_<ip_secondary1>_volume1/applis-apsu-data-glusterfs-volume1-brick1-brick/.processing/CHANGELOG.1642088236}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.71075] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):1207:process_change] _GMaster: entries: []
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.71938] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):317:a_syncdata] _GMaster: files [{files=set(['.gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1'])}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.72045] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.107691] D [resource(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):1442:rsync] SSH: files: .gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.222352] I [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):2013:syncjob] Syncer: Sync Time Taken [{duration=0.1146}, {num_files=1}, {job=2}, {return_code=23}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.222870] W [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1642088236']}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.724687] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):317:a_syncdata] _GMaster: files [{files=set(['.gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1'])}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/gsyncd.log:[2022-01-13 15:37:22.724937] D [master(worker /applis/apsu/data/glusterfs/volume1/brick1/brick):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1}]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.058930 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.059538 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.206421 +0000] D [rpc-clnt-ping.c:96:rpc_clnt_remove_ping_timer_locked] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x137)[0x7fb0e9377ec7] (--> /lib64/libgfrpc.so.0(+0x1366e)[0x7fb0e912266e] (--> /lib64/libgfrpc.so.0(+0x13e11)[0x7fb0e9122e11] (--> /lib64/libgfrpc.so.0(rpc_clnt_submit+0x3d7)[0x7fb0e911f0b7] (--> /usr/lib64/glusterfs/9.4/xlator/protocol/client.so(+0x157a2)[0x7fb0da7897a2] ))))) 0-: <ip_primary2>:49152: ping timer event already removed
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.206674 +0000] D [rpc-clnt-ping.c:96:rpc_clnt_remove_ping_timer_locked] (--> /lib64/libglusterfs.so.0(_gf_log_callingfn+0x137)[0x7fb0e9377ec7] (--> /lib64/libgfrpc.so.0(+0x1366e)[0x7fb0e912266e] (--> /lib64/libgfrpc.so.0(+0x13e11)[0x7fb0e9122e11] (--> /lib64/libgfrpc.so.0(rpc_clnt_submit+0x3d7)[0x7fb0e911f0b7] (--> /usr/lib64/glusterfs/9.4/xlator/protocol/client.so(+0x157a2)[0x7fb0da7897a2] ))))) 0-: <ip_primary3>:49152: ping timer event already removed
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.206699 +0000] D [rpc-clnt-ping.c:195:rpc_clnt_ping_cbk] 0-volume1-client-1: Ping latency is 0ms
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207003 +0000] D [rpc-clnt-ping.c:195:rpc_clnt_ping_cbk] 0-volume1-client-2: Ping latency is 0ms
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207493 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207522 +0000] D [MSGID: 0] [gfid-access.c:1169:ga_getxattr] 0-stack-trace: stack-address: 0x7fb0bc00f2c8, gfid-access-autoload returned -1 error: Operation not supported [Operation not supported]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207543 +0000] E [fuse-bridge.c:4336:fuse_xattr_cbk] 0-glusterfs-fuse: extended attribute not supported by the backend storage
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207619 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207840 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207866 +0000] D [MSGID: 0] [md-cache.c:2509:mdc_getxattr] 0-stack-trace: stack-address: 0x7fb0bc00f2c8, volume1-md-cache returned -1 error: No data available [No data available]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207889 +0000] D [MSGID: 0] [defaults.c:1454:default_getxattr_cbk] 0-stack-trace: stack-address: 0x7fb0bc00f2c8, posix-acl-autoload returned -1 error: No data available [No data available]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207905 +0000] D [MSGID: 0] [defaults.c:1454:default_getxattr_cbk] 0-stack-trace: stack-address: 0x7fb0bc00f2c8, gfid-access-autoload returned -1 error: No data available [No data available]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207918 +0000] D [fuse-bridge.c:4347:fuse_xattr_cbk] 0-glusterfs-fuse: 7846: GETXATTR(system.posix_acl_access) /.gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1 => -1 (No data available)
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208121 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208464 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting op_ret to 0 from 12
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208647 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208682 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208927 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting op_ret to 0 from 57
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.209033 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.209065 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.209322 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting op_ret to 0 from 57
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213528 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213572 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213807 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting op_ret to 0 from 57
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213916 +0000] D [fuse-helpers.c:615:fuse_flip_xattr_ns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark*, *xtime
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213949 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.214221 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting op_ret to 0 from 57
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:The message "D [MSGID: 0] [gfid-access.c:1169:ga_getxattr] 0-stack-trace: stack-address: 0x7fb0bc00f2c8, gfid-access-autoload returned -1 error: Operation not supported [Operation not supported]" repeated 5 times between [2022-01-13 15:37:22.207522 +0000] and [2022-01-13 15:37:23.200611 +0000]
/var/log/glusterfs/geo-replication/volume1_<ip_secondary1>_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:The message "D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting op_ret to 0 from 57" repeated 4 times between [2022-01-13 15:37:22.214221 +0000] and [2022-01-13 15:37:23.206238 +0000]
Shwetha-Acharya commented 2 years ago

/var/log/glusterfs/geo-replication/volume1__volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.207918 +0000] D [fuse-bridge.c:4347:fuse_xattr_cbk] 0-glusterfs-fuse: 7846: GETXATTR(system.posix_aclaccess) /.gfid/25d46d1b-1e67-4f2a-b477-fbdff21c44f1 => -1 (No data available) /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208121 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_readtxn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208464 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting opret to 0 from 12 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208647 +0000] D [fuse-helpers.c:615:fuse_flip_xattrns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark, xtime /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208682 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_readtxn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.208927 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting opret to 0 from 57 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.209033 +0000] D [fuse-helpers.c:615:fuse_flip_xattrns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark, xtime /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.209065 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_readtxn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.209322 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting opret to 0 from 57 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213528 +0000] D [fuse-helpers.c:615:fuse_flip_xattrns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark, xtime /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213572 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_readtxn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, 3 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213807 +0000] D [MSGID: 0] [client-rpc-fops_v2.c:917:client4_0_getxattr_cbk] 0-volume1-client-0: resetting opret to 0 from 57 /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213916 +0000] D [fuse-helpers.c:615:fuse_flip_xattrns] 0-glusterfs-fuse: PID: -1, checking xattr(s): volume-mark, xtime /var/log/glusterfs/geo-replication/volume1_volume1/mnt-applis-apsu-data-glusterfs-volume1-brick1-brick.log:[2022-01-13 15:37:22.213949 +0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-+0000] D [MSGID: 0] [afr-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: genfbdff21c44f1: generatio-read-txn.c:455:afr_read_txn] 0-volume1-replicate-0: 25d46d1b-1e67-4f2a-b477-fbdff21c44f1: generation now vs cached: 3, n now vs cached: 3, 3

These look related to AFR. @karthik-us could you please take a look at these errors?

stale[bot] commented 2 years ago

Thank you for your contributions. Noticed that this issue is not having any activity in last ~6 months! We are marking this issue as stale because it has not had recent activity. It will be closed in 2 weeks if no one responds with a comment here.

stale[bot] commented 2 years ago

Closing this issue as there was no update since my last update on issue. If this is an issue which is still valid, feel free to open it.

pbiering commented 5 months ago

I found such log entries very sporadic on various mirrored volumes, what can be the trigger for this? Any ideas how to investigate further or what can I do to trigger this explicitly?

I was able to add/remove an attribute to a file in the mounted gfs volume, this has not triggered any error.