Bug 1311250
| Summary: | Failure to propagate directory extended file attributes to slaves | ||
|---|---|---|---|
| Product: | [Community] GlusterFS | Reporter: | gerald <gerald> |
| Component: | geo-replication | Assignee: | Kotresh HR <khiremat> |
| Status: | CLOSED EOL | QA Contact: | |
| Severity: | high | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 3.7.6 | CC: | avishwan, bugs, chrisw, csaba, nlevinki, vbellur |
| Target Milestone: | --- | Keywords: | Triaged |
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2017-03-08 10:49:39 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
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. |
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