1311250 – Failure to propagate directory extended file attributes to slaves

Bug 1311250 - Failure to propagate directory extended file attributes to slaves

Summary: Failure to propagate directory extended file attributes to slaves

Keywords:
Status:	CLOSED EOL
Alias:	None
Product:	GlusterFS
Classification:	Community
Component:	geo-replication
Sub Component:
Version:	3.7.6
Hardware:	Unspecified
OS:	Linux
Priority:	unspecified
Severity:	high
Target Milestone:	---
Assignee:	Kotresh HR
QA Contact:
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2016-02-23 17:55 UTC by gerald
Modified:	2017-03-08 10:49 UTC (History)
CC List:	6 users (show)
Fixed In Version:
Clone Of:
Environment:
Last Closed:	2017-03-08 10:49:39 UTC
Regression:	---
Mount Type:	---
Documentation:	---
CRM:
Verified Versions:
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Description gerald 2016-02-23 17:55:52 UTC

Description of problem:
When creating a new directory, there seems to be a problem with simultaneously setting extended attributes. Files are set correctly
The acl is set on the master but not propagated to the slave
Subsequent attempts to explicitly set the acl are honored on the master but ignored on the slave
    mkdir /mounted/gluster/volume directory; setfacl -m g:group:perm /mounted/gluster/volume/directory
    master ok
    slave no go
If the acl is completely removed and then re-added to the file, it is honored on the master and propagated to the slave
    mkdir /mounted/gluster/volume directory; setfacl -m g:group:perm /mounted/gluster/volume/directory
    setfacl -b setfacl  /mounted/gluster/volume/directory
    setfacl -m g:group:perm /mounted/gluster/volume/directory
or
    mkdir /mounted/gluster/volume directory
    sleep 20
    setfacl -m g:group:perm /mounted/gluster/volume/directory

    master ok
    slave ok


Version-Release number of selected component (if applicable):
3.7.6

How reproducible:
repeatable


Steps to Reproduce:
1.    mkdir /mounted/gluster/volume directory; setfacl -m g:group:perm /mounted/gluster/volume/directory


Actual results:
no extended attributes on directory

Expected results:
extended attributes mirror master directory extended attributes

Additional info:

fstab master
chifsv1:DataUserCHI-on-chifsv1		/home/samba/data.user.chi	glusterfs	defaults,acl	0 0

fstab slave
rocfsv0:DataUserCHI-on-rocfsv0		/home/samba/data.user.chi	glusterfs	defaults,acl	0 0


glusterfs mount log
[2016-02-19 00:56:40.323883] I [MSGID: 109036] [dht-common.c:7869:dht_log_new_layout_for_dir_selfheal] 0-DataUserCHI-on-chifsv1-dht: Setting layout of /test00/My Videos with [Subvol_name: DataUserCHI-on-chifsv1-client-0, Err: -1 , Start: 0 , Stop: 4294967295 , Hash: 1 ], 
[2016-02-19 00:56:45.541597] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:56:45.541736] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:56:45.785983] I [MSGID: 109036] [dht-common.c:7869:dht_log_new_layout_for_dir_selfheal] 0-DataUserCHI-on-chifsv1-dht: Setting layout of /test00/My Pictures with [Subvol_name: DataUserCHI-on-chifsv1-client-0, Err: -1 , Start: 0 , Stop: 4294967295 , Hash: 1 ], 
[2016-02-19 00:56:50.919080] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:56:50.919172] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:56:51.166527] I [MSGID: 109036] [dht-common.c:7869:dht_log_new_layout_for_dir_selfheal] 0-DataUserCHI-on-chifsv1-dht: Setting layout of /test00/My Music with [Subvol_name: DataUserCHI-on-chifsv1-client-0, Err: -1 , Start: 0 , Stop: 4294967295 , Hash: 1 ], 
[2016-02-19 00:56:56.294073] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:56:56.294172] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:56:57.833735] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:56:57.833819] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:56:57.918384] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:56:57.918457] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:57:02.089777] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:57:02.089851] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:57:16.809624] I [MSGID: 109066] [dht-rename.c:1411:dht_rename] 0-DataUserCHI-on-chifsv1-dht: renaming /test00/profile.V2/NTUSER.DAT (hash=DataUserCHI-on-chifsv1-client-0/cache=DataUserCHI-on-chifsv1-client-0) => /test00/profile.V2/prf9B1E.tmp (hash=DataUserCHI-on-chifsv1-client-0/cache=DataUserCHI-on-chifsv1-client-0)
[2016-02-19 00:57:16.935594] I [MSGID: 109066] [dht-rename.c:1411:dht_rename] 0-DataUserCHI-on-chifsv1-dht: renaming /test00/profile.V2/ntuser.pol (hash=DataUserCHI-on-chifsv1-client-0/cache=DataUserCHI-on-chifsv1-client-0) => /test00/profile.V2/prf9B8C.tmp (hash=DataUserCHI-on-chifsv1-client-0/cache=DataUserCHI-on-chifsv1-client-0)
[2016-02-19 00:57:17.949075] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:57:17.949132] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:57:18.327295] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:57:18.327349] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:57:18.954997] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1a9) [0x7f8b79e7ee79] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_access [Invalid argument]
[2016-02-19 00:57:18.955065] I [dict.c:473:dict_get] (-->/usr/lib/glusterfs/3.7.6/xlator/debug/io-stats.so(io_stats_lookup_cbk+0xe5) [0x7f8b7a094b35] -->/usr/lib/glusterfs/3.7.6/xlator/system/posix-acl.so(posix_acl_lookup_cbk+0x1f8) [0x7f8b79e7eec8] -->/usr/lib/libglusterfs.so.0(dict_get+0x93) [0x7f8b817c3dd3] ) 0-dict: !this || key=system.posix_acl_default [Invalid argument]
[2016-02-19 00:56:58.745073] I [MSGID: 109036] [dht-common.c:7869:dht_log_new_layout_for_dir_selfheal] 0-DataUserCHI-on-chifsv1-dht: Setting layout of /test00/My Music with [Subvol_name: DataUserCHI-on-chifsv1-client-0, Err: -1 , Start: 0 , Stop: 4294967295 , Hash: 1 ], 
[2016-02-19 00:56:58.766225] I [MSGID: 109036] [dht-common.c:7869:dht_log_new_layout_for_dir_selfheal] 0-DataUserCHI-on-chifsv1-dht: Setting layout of /test00/My Pictures with [Subvol_name: DataUserCHI-on-chifsv1-client-0, Err: -1 , Start: 0 , Stop: 4294967295 , Hash: 1 ], 
[2016-02-19 00:56:58.817647] I [MSGID: 109036] [dht-common.c:7869:dht_log_new_layout_for_dir_selfheal] 0-DataUserCHI-on-chifsv1-dht: Setting layout of /test00/My Videos with [Subvol_name: DataUserCHI-on-chifsv1-client-0, Err: -1 , Start: 0 , Stop: 4294967295 , Hash: 1 ],

geo-replication/brick logs

*gluster.log
[2016-02-19 00:37:31.521080] E [fuse-bridge.c:3347:fuse_xattr_cbk] 0-glusterfs-fuse: extended attribute not supported by the backend storage
[2016-02-19 00:56:35.899277] E [fuse-bridge.c:3347:fuse_xattr_cbk] 0-glusterfs-fuse: extended attribute not supported by the backend storage

*changes.log
[2016-02-19 00:56:17.810412] T [rpcsvc-auth.c:404:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v2
[2016-02-19 00:56:17.810480] T [rpcsvc.c:495:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x18, Ver: 2, Program: 1886350951, ProgVers: 1, Proc: 1) from rpc-transport (socket.gfchangelog)
[2016-02-19 00:56:17.810545] T [auth-glusterfs.c:242:auth_glusterfs_v2_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 00000000
[2016-02-19 00:56:17.810558] T [rpcsvc.c:316:rpcsvc_program_actor] 0-rpc-service: Actor found: LIBGFCHANGELOG REBORP - CHANGELOG EVENT HANDLER for 
[2016-02-19 00:56:17.810584] D [gf-changelog-reborp.c:406:gf_changelog_event_handler] 0-gfchangelog: seq: 558 [/home/gluster/data.user.chi] (time: 1455843377.810167), (vec: 1, len: 4104)
[2016-02-19 00:56:17.810637] T [rpcsvc.c:1273:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2016-02-19 00:56:17.810652] T [rpcsvc.c:863:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2016-02-19 00:56:17.810676] T [rpcsvc.c:1321:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x12, Program: LIBGFCHANGELOG REBORP, ProgVers: 1, Proc: 1) to rpc-transport (socket.gfchangelog)
[2016-02-19 00:56:39.063145] D [gf-changelog-api.c:53:gf_changelog_done] 0-gfchangelog: moving /home/gluster/log/lib/misc/glusterfsd/DataUserCHI-on-chifsv1/ssh%3A%2F%2Froot%40192.168.60.104%3Agluster%3A%2F%2F127.0.0.1%3ADataUserCHI-on-rocfsv0/9635bcc6a395a2058103ffe915720da3/.processing/CHANGELOG.1455843377 to processed directory
[2016-02-19 00:56:47.841798] T [rpcsvc-auth.c:404:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v2
[2016-02-19 00:56:47.841855] T [rpcsvc.c:495:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x19, Ver: 2, Program: 1886350951, ProgVers: 1, Proc: 1) from rpc-transport (socket.gfchangelog)
[2016-02-19 00:56:47.841875] T [auth-glusterfs.c:242:auth_glusterfs_v2_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 00000000
[2016-02-19 00:56:47.841885] T [rpcsvc.c:316:rpcsvc_program_actor] 0-rpc-service: Actor found: LIBGFCHANGELOG REBORP - CHANGELOG EVENT HANDLER for 
[2016-02-19 00:56:47.841900] D [gf-changelog-reborp.c:406:gf_changelog_event_handler] 0-gfchangelog: seq: 559 [/home/gluster/data.user.chi] (time: 1455843407.841570), (vec: 1, len: 4104)
[2016-02-19 00:56:47.841938] T [rpcsvc.c:1273:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2016-02-19 00:56:47.841949] T [rpcsvc.c:863:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2016-02-19 00:56:47.841966] T [rpcsvc.c:1321:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x13, Program: LIBGFCHANGELOG REBORP, ProgVers: 1, Proc: 1) to rpc-transport (socket.gfchangelog)
[2016-02-19 00:56:48.452898] D [gf-changelog-api.c:53:gf_changelog_done] 0-gfchangelog: moving /home/gluster/log/lib/misc/glusterfsd/DataUserCHI-on-chifsv1/ssh%3A%2F%2Froot%40192.168.60.104%3Agluster%3A%2F%2F127.0.0.1%3ADataUserCHI-on-rocfsv0/9635bcc6a395a2058103ffe915720da3/.processing/CHANGELOG.1455843407 to processed directory
[2016-02-19 00:57:02.853766] T [rpcsvc-auth.c:404:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v2
[2016-02-19 00:57:02.853849] T [rpcsvc.c:495:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x20, Ver: 2, Program: 1886350951, ProgVers: 1, Proc: 1) from rpc-transport (socket.gfchangelog)
[2016-02-19 00:57:02.853878] T [auth-glusterfs.c:242:auth_glusterfs_v2_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 00000000
[2016-02-19 00:57:02.853889] T [rpcsvc.c:316:rpcsvc_program_actor] 0-rpc-service: Actor found: LIBGFCHANGELOG REBORP - CHANGELOG EVENT HANDLER for 
[2016-02-19 00:57:02.853912] D [gf-changelog-reborp.c:406:gf_changelog_event_handler] 0-gfchangelog: seq: 560 [/home/gluster/data.user.chi] (time: 1455843422.853491), (vec: 1, len: 4104)
[2016-02-19 00:57:02.853959] T [rpcsvc.c:1273:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2016-02-19 00:57:02.853972] T [rpcsvc.c:863:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2016-02-19 00:57:02.853993] T [rpcsvc.c:1321:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x14, Program: LIBGFCHANGELOG REBORP, ProgVers: 1, Proc: 1) to rpc-transport (socket.gfchangelog)
[2016-02-19 00:57:04.468179] D [gf-changelog-api.c:53:gf_changelog_done] 0-gfchangelog: moving /home/gluster/log/lib/misc/glusterfsd/DataUserCHI-on-chifsv1/ssh%3A%2F%2Froot%40192.168.60.104%3Agluster%3A%2F%2F127.0.0.1%3ADataUserCHI-on-rocfsv0/9635bcc6a395a2058103ffe915720da3/.processing/CHANGELOG.1455843422 to processed directory
[2016-02-19 00:57:17.871711] T [rpcsvc-auth.c:404:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v2
[2016-02-19 00:57:17.871750] T [rpcsvc.c:495:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x21, Ver: 2, Program: 1886350951, ProgVers: 1, Proc: 1) from rpc-transport (socket.gfchangelog)
[2016-02-19 00:57:17.871767] T [auth-glusterfs.c:242:auth_glusterfs_v2_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 00000000
[2016-02-19 00:57:17.871773] T [rpcsvc.c:316:rpcsvc_program_actor] 0-rpc-service: Actor found: LIBGFCHANGELOG REBORP - CHANGELOG EVENT HANDLER for 
[2016-02-19 00:57:17.871787] D [gf-changelog-reborp.c:406:gf_changelog_event_handler] 0-gfchangelog: seq: 561 [/home/gluster/data.user.chi] (time: 1455843437.871483), (vec: 1, len: 4104)
[2016-02-19 00:57:17.871808] T [rpcsvc.c:1273:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2016-02-19 00:57:17.871816] T [rpcsvc.c:863:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2016-02-19 00:57:17.871828] T [rpcsvc.c:1321:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x15, Program: LIBGFCHANGELOG REBORP, ProgVers: 1, Proc: 1) to rpc-transport (socket.gfchangelog)
[2016-02-19 00:57:32.949548] T [rpcsvc-auth.c:404:rpcsvc_auth_request_init] 0-rpc-service: Auth handler: AUTH_GLUSTERFS-v2
[2016-02-19 00:57:32.949596] T [rpcsvc.c:495:rpcsvc_request_create] 0-rpc-service: received rpc-message (XID: 0x22, Ver: 2, Program: 1886350951, ProgVers: 1, Proc: 1) from rpc-transport (socket.gfchangelog)
[2016-02-19 00:57:32.949618] T [auth-glusterfs.c:242:auth_glusterfs_v2_authenticate] 0-rpc-service: Auth Info: pid: 0, uid: 0, gid: 0, owner: 00000000
[2016-02-19 00:57:32.949625] T [rpcsvc.c:316:rpcsvc_program_actor] 0-rpc-service: Actor found: LIBGFCHANGELOG REBORP - CHANGELOG EVENT HANDLER for 
[2016-02-19 00:57:32.949640] D [gf-changelog-reborp.c:406:gf_changelog_event_handler] 0-gfchangelog: seq: 562 [/home/gluster/data.user.chi] (time: 1455843452.949248), (vec: 1, len: 4104)
[2016-02-19 00:57:32.949670] T [rpcsvc.c:1273:rpcsvc_submit_generic] 0-rpc-service: Tx message: 8
[2016-02-19 00:57:32.949702] T [rpcsvc.c:863:rpcsvc_record_build_header] 0-rpc-service: Reply fraglen 32, payload: 8, rpc hdr: 24
[2016-02-19 00:57:32.949721] T [rpcsvc.c:1321:rpcsvc_submit_generic] 0-rpc-service: submitted reply for rpc-message (XID: 0x16, Program: LIBGFCHANGELOG REBORP, ProgVers: 1, Proc: 1) to rpc-transport (socket.gfchangelog)
[2016-02-19 00:57:37.436565] D [gf-changelog-api.c:53:gf_changelog_done] 0-gfchangelog: moving /home/gluster/log/lib/misc/glusterfsd/DataUserCHI-on-chifsv1/ssh%3A%2F%2Froot%40192.168.60.104%3Agluster%3A%2F%2F127.0.0.1%3ADataUserCHI-on-rocfsv0/9635bcc6a395a2058103ffe915720da3/.processing/CHANGELOG.1455843437 to processed directory
[2016-02-19 00:57:42.047354] D [gf-changelog-api.c:53:gf_changelog_done] 0-gfchangelog: moving /home/gluster/log/lib/misc/glusterfsd/DataUserCHI-on-chifsv1/ssh%3A%2F%2Froot%40192.168.60.104%3Agluster%3A%2F%2F127.0.0.1%3ADataUserCHI-on-rocfsv0/9635bcc6a395a2058103ffe915720da3/.processing/CHANGELOG.1455843452 to processed directory

Rocfsv0.log:
[2016-02-18 18:56:18.196230] I [master(/home/gluster/data.user.chi):1104:crawl] _GMaster: slave's time: (1455842564, 0)
[2016-02-18 18:56:20.348185] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:22.442728] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:24.455387] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:26.575637] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:28.825910] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:30.763843] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:32.744244] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:34.800153] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:36.841928] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843377
[2016-02-18 18:56:39.25330] W [master(/home/gluster/data.user.chi):1019:process] _GMaster: changelogs CHANGELOG.1455843377 could not be processed - moving on...
[2016-02-18 18:56:39.46524] W [master(/home/gluster/data.user.chi):1023:process] _GMaster: SKIPPED GFID = 60e007a2-adef-49b6-ad5f-07080c6b45ac,6cd71c1c-fef8-4179-9e22-ca6e114c2671,2404262a-ccd5-4071-947b-25647dc13772,4031f4d8-0e50-4eb6-a21d-81300d37b7d9,9b748d02-794c-4b27-ba57-73cfddebdb1a,9cf47723-ba10-405f-b5d9-c338e28cd298,92f6ea24-8112-4c60-93e8-d932ee5e283a,fe22d62e-3da4-4525-a4bc-f5ce0eb8302e,baf1f12b-aa2d-4307-9605-3d5937d08066,22fade80-db2e-42cb-9cb5-1456bb1015a8,3c809b85-1341-42d9-af4e-e8bb57a4a67a,95d0023c-1653-425c-90c9-5f1ffe675b2b,115b381b-460f-482f-9aab-47036cd0ea46,7295953e-f871-43e3-abba-fda8047923a9,59bf4d90-1857-4da6-be39-07150ec64587,61b181a1-5acc-4286-9d1c-4101e1cd7828,4e643c15-fda2-40a7-b620-67bf1345ca73,c0223432-c092-4ed5-8c78-ff21734dd94b,03e63a1c-204e-484a-bd48-816fb0dd2512,0655c1c1-be1f-4553-ac38-9527a58a0da1,14c170f0-8f87-47a3-bce3-81fd6afd948b,2a951323-d287-492a-a825-4dd4f1c9428c,5f2061fa-193b-4fdf-a302-5f86c5abf14e,e7cf3d82-6365-4bc3-83c2-83f090b858dd,a737d2fd-6d2a-4776-9f1c-1fa6700a1656,4db1cfc9-7352-42a9-8ac7-77b62177cb9a,0d4caccf-d246-4c82-8f42-934ed3e5b23a,be34344a-7a9b-41aa-9826-b5c4bdca7f04,1383bf50-2431-4ecb-ae17-fa52123147c8,f3cecd8e-4f75-4f58-bcde-5d4fab8cf668,7496012f-c007-47d1-8d06-94596d3b257f,af8e0371-ddaa-4b7d-a9be-760237602611,919e1c17-126b-48bb-bcb9-928905978983,c2e2ddad-8249-4a59-a20a-c8076771052e,30a60b5b-c6c4-4639-919c-24e0524114fa,5827e856-719d-4218-b173-a71f5d701037,c023801c-92f1-4c77-afb9-72c741ae1f1e,d10ba6d1-4937-4bd0-afa7-e8b222a687ff,8d20990a-2b64-4fd8-8d00-9e85057a748f,4823bb23-3b4c-422a-a384-e92089cceb52,06b573de-1517-4949-99f5-94512d769b6e,b1c505ad-8ab6-417f-858c-106144cc7602,2192c2ab-3844-4037-81bc-d08f3b3cfca5,9bed7039-2e6d-47a9-8d3f-32d7a5e2db2c,6a8e3142-5e09-41b3-9df0-a8684ccb3364,656598a0-e198-4ea6-86fa-fd66363cb1dd,0b802e11-432f-4cff-822d-c3a123ca3571,c45b1d73-94da-4a3b-8edb-237d7dc72cb3,05126f5a-be4f-4ea5-bb1f-8e72c75e7e7f,39cd32a4-3128-41a9-b91b-3cc7e2a9ec3c,2895aed8-ffe6-4001-a16c-9dc1b2bd8d92,e843983c-375e-49bc-80b6-e4baacd8090b,4213241c-aab9-42b8-8c62-8b5c886c4bec,9c698700-84f5-4524-bd56-a940148dbdf8,dfb35c50-7321-417f-ab4d-54ce599d551c,13d51469-6c76-41e0-a6e9-d64b1bd1b52a,cd17b776-4bde-4903-8f0d-4c6dad03a202,f5b9a37b-6252-49b1-b4fd-cd63074a04d7,80131eeb-fab8-470a-aa12-015140b94cdf,09b780c4-6a40-4b28-b412-5198b9df3c51,fd81adad-0c02-4420-b463-ea7a50988bb1,a1217996-1d56-47f5-a7de-04e0bfd3cb80,aad73cd3-e8cf-4021-a8e2-a2ccebd804a5,95771fa8-acdf-4855-bf9b-6bd558eb2295
[2016-02-18 18:56:42.115962] I [master(/home/gluster/data.user.chi):552:crawlwrap] _GMaster: 15 crawls, 1 turns
[2016-02-18 18:56:48.245609] I [master(/home/gluster/data.user.chi):1104:crawl] _GMaster: slave's time: (1455843376, 0)
[2016-02-18 18:57:03.755646] I [master(/home/gluster/data.user.chi):1104:crawl] _GMaster: slave's time: (1455843406, 0)
[2016-02-18 18:57:19.908150] I [master(/home/gluster/data.user.chi):1104:crawl] _GMaster: slave's time: (1455843421, 0)
[2016-02-18 18:57:21.618351] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:23.379271] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:25.325232] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:26.891222] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:28.629333] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:30.369771] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:32.44816] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:33.871902] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:35.469685] W [master(/home/gluster/data.user.chi):1050:process] _GMaster: incomplete sync, retrying changelogs: CHANGELOG.1455843437
[2016-02-18 18:57:37.401856] W [master(/home/gluster/data.user.chi):1019:process] _GMaster: changelogs CHANGELOG.1455843437 could not be processed - moving on...
[2016-02-18 18:57:37.410121] W [master(/home/gluster/data.user.chi):1023:process] _GMaster: SKIPPED GFID = 6cd71c1c-fef8-4179-9e22-ca6e114c2671,2404262a-ccd5-4071-947b-25647dc13772,4031f4d8-0e50-4eb6-a21d-81300d37b7d9,c0223432-c092-4ed5-8c78-ff21734dd94b,9b748d02-794c-4b27-ba57-73cfddebdb1a,92f6ea24-8112-4c60-93e8-d932ee5e283a,fe22d62e-3da4-4525-a4bc-f5ce0eb8302e,baf1f12b-aa2d-4307-9605-3d5937d08066,95d0023c-1653-425c-90c9-5f1ffe675b2b,115b381b-460f-482f-9aab-47036cd0ea46,7295953e-f871-43e3-abba-fda8047923a9,59bf4d90-1857-4da6-be39-07150ec64587,4e643c15-fda2-40a7-b620-67bf1345ca73,61b181a1-5acc-4286-9d1c-4101e1cd7828,03e63a1c-204e-484a-bd48-816fb0dd2512,0655c1c1-be1f-4553-ac38-9527a58a0da1,14c170f0-8f87-47a3-bce3-81fd6afd948b,2a951323-d287-492a-a825-4dd4f1c9428c,5f2061fa-193b-4fdf-a302-5f86c5abf14e,e7cf3d82-6365-4bc3-83c2-83f090b858dd,4db1cfc9-7352-42a9-8ac7-77b62177cb9a,be34344a-7a9b-41aa-9826-b5c4bdca7f04,7496012f-c007-47d1-8d06-94596d3b257f,13d51469-6c76-41e0-a6e9-d64b1bd1b52a,68df099e-12c3-4523-a3ff-6b812891813b,c2e2ddad-8249-4a59-a20a-c8076771052e,30a60b5b-c6c4-4639-919c-24e0524114fa,5827e856-719d-4218-b173-a71f5d701037,8d20990a-2b64-4fd8-8d00-9e85057a748f,4823bb23-3b4c-422a-a384-e92089cceb52,06b573de-1517-4949-99f5-94512d769b6e,b1c505ad-8ab6-417f-858c-106144cc7602,2192c2ab-3844-4037-81bc-d08f3b3cfca5,9bed7039-2e6d-47a9-8d3f-32d7a5e2db2c,6a8e3142-5e09-41b3-9df0-a8684ccb3364,0b802e11-432f-4cff-822d-c3a123ca3571,05126f5a-be4f-4ea5-bb1f-8e72c75e7e7f,39cd32a4-3128-41a9-b91b-3cc7e2a9ec3c,2895aed8-ffe6-4001-a16c-9dc1b2bd8d92,3fcfe5b5-b242-43f9-820e-b3b7e1ba56ae,4213241c-aab9-42b8-8c62-8b5c886c4bec,9c698700-84f5-4524-bd56-a940148dbdf8,cd17b776-4bde-4903-8f0d-4c6dad03a202,f5b9a37b-6252-49b1-b4fd-cd63074a04d7,80131eeb-fab8-470a-aa12-015140b94cdf,09b780c4-6a40-4b28-b412-5198b9df3c51,fd81adad-0c02-4420-b463-ea7a50988bb1,a1217996-1d56-47f5-a7de-04e0bfd3cb80,aad73cd3-e8cf-4021-a8e2-a2ccebd804a5,95771fa8-acdf-4855-bf9b-6bd558eb2295
[2016-02-18 18:57:40.539343] I [master(/home/gluster/data.user.chi):1104:crawl] _GMaster: slave's time: (1455843436, 0)
[2016-02-18 18:57:45.117387] I [master(/home/gluster/data.user.chi):552:crawlwrap] _GMaster: 14 crawls, 4 turns
[2016-02-18 18:58:46.118089] I [master(/home/gluster/data.user.chi):552:crawlwrap] _GMaster: 20 crawls, 0 turns

Comment 2 Kaushal 2017-03-08 10:49:39 UTC

This bug is getting closed because GlusteFS-3.7 has reached its end-of-life.

Note: This bug is being closed using a script. No verification has been performed to check if it still exists on newer releases of GlusterFS.
If this bug still exists in newer GlusterFS releases, please reopen this bug against the newer release.

Note You need to log in before you can comment on or make changes to this bug.