<div dir="ltr"><div>Hi Strahil,</div><div><br></div><div>The CPU is still quite high, with &quot;top&quot; regularly showing 100% CPU usage by that process. However it&#39;s not clear whether this is really a problem, or if it&#39;s just normal geo-replication activity. While CPU usage was not previously as high on this server, it&#39;s not clear whether GlusterFS might have made this the &quot;push&quot; node for geo-replication when it used to be some other server. Having said that, no other server shows a sudden drop in CPU usage.<br></div><div><br></div><div>Ideally we could find out what the gsyncd process is doing, and therefore whether it&#39;s expected or not. Any ideas on that? We did set the log level to DEBUG as Sunny suggested.<br></div><div><br></div><div>Looking at /var/log/glusterfs/geo-replication-slaves/gvol0_nvfs10_gvol0/mnt-cafs30-nodirectwritedata-gluster-gvol0.log on the geo-replication slave, we have a lot of lines like the following logged. <br></div><br><div>[2020-06-06 00:32:43.155856] W [fuse-bridge.c:897:fuse_attr_cbk] 0-glusterfs-fuse: 875853: STAT() /.gfid/25d78a6c-41a9-4364-84a8-31f5571223ac =&gt; -1 (Stale file handle)<br>[2020-06-06 00:32:43.219759] W [fuse-bridge.c:897:fuse_attr_cbk] 0-glusterfs-fuse: 875923: STAT() /.gfid/25d78a6c-41a9-4364-84a8-31f5571223ac =&gt; -1 (Stale file handle)<br>[2020-06-06 00:32:43.280357] W [fuse-bridge.c:897:fuse_attr_cbk] 0-glusterfs-fuse: 876001: STAT() /.gfid/25d78a6c-41a9-4364-84a8-31f5571223ac =&gt; -1 (Stale file handle)<br>The message &quot;E [MSGID: 109040] [dht-helper.c:1332:dht_migration_complete_check_task] 0-gvol0-dht: /.gfid/25d78a6c-41a9-4364-84a8-31f5571223ac: failed to lookup the file on gvol0-dht [Stale file handle]&quot; repeated 9 times between [2020-06-06 00:32:42.689780] and [2020-06-06 00:32:43.280322]<br>[2020-06-06 09:03:03.660956] E [MSGID: 109040] [dht-helper.c:1332:dht_migration_complete_check_task] 0-gvol0-dht: /.gfid/decdd552-d58b-4ddf-b27a-0da9a6fbc38b: failed to lookup the file on gvol0-dht [Stale file handle]<br>[2020-06-06 09:03:03.661057] W [fuse-bridge.c:897:fuse_attr_cbk] 0-glusterfs-fuse: 965375: STAT() /.gfid/decdd552-d58b-4ddf-b27a-0da9a6fbc38b =&gt; -1 (Stale file handle)<br>[2020-06-06 09:03:10.258798] E [MSGID: 109040] [dht-helper.c:1332:dht_migration_complete_check_task] 0-gvol0-dht: /.gfid/1d90e129-d40f-4ca4-bea8-0bb3c4c7985a: failed to lookup the file on gvol0-dht [Stale file handle]<br>[2020-06-06 09:03:10.258880] W [fuse-bridge.c:897:fuse_attr_cbk] 0-glusterfs-fuse: 969455: STAT() /.gfid/1d90e129-d40f-4ca4-bea8-0bb3c4c7985a =&gt; -1 (Stale file handle)<br>[2020-06-06 09:09:41.259362] E [MSGID: 109040] [dht-helper.c:1332:dht_migration_complete_check_task] 0-gvol0-dht: /.gfid/740efff6-74dd-45be-847f-66919d1179e0: failed to lookup the file on gvol0-dht [Stale file handle]<br>[2020-06-06 09:09:41.259458] W [fuse-bridge.c:897:fuse_attr_cbk] 0-glusterfs-fuse: 1040904: STAT() /.gfid/740efff6-74dd-45be-847f-66919d1179e0 =&gt; -1 (Stale file handle)</div><div><br></div><div>Could these errors be part of the problem?</div><div><br></div><div>Thanks again.</div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Sat, 6 Jun 2020 at 21:21, Strahil Nikolov &lt;<a href="mailto:hunter86_bg@yahoo.com">hunter86_bg@yahoo.com</a>&gt; wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">Hey David,<br>
<br>
can you check the old logs for gfid mismatch and get a list  of files that were causing the high cpu .<br>
Maybe they are  related  somehow (maybe created by the same software  ,  same client version or something else) which could help about that.<br>
<br>
Also  take  a  look in geo-replication-slave logs.<br>
<br>
Does the issue still occurs ?<br>
<br>
Best Regards,<br>
Strahil Nikolov<br>
<br>
На 6 юни 2020 г. 1:21:55 GMT+03:00, David Cunningham &lt;<a href="mailto:dcunningham@voisonics.com" target="_blank">dcunningham@voisonics.com</a>&gt; написа:<br>
&gt;Hi Sunny and Strahil,<br>
&gt;<br>
&gt;Thanks again for your responses. We don&#39;t have a lot of renaming<br>
&gt;activity -<br>
&gt;maybe some, but not a lot. We do have files which are open for writing<br>
&gt;for<br>
&gt;quite a while - they&#39;re call recordings being written as the call<br>
&gt;happens.<br>
&gt;<br>
&gt;We&#39;ve installed GlusterFS using the Ubuntu packages and I&#39;d really like<br>
&gt;to<br>
&gt;avoid compiling and applying patches.<br>
&gt;<br>
&gt;After enabling DEBUG the log at<br>
&gt;/var/log/glusterfs/geo-replication/gvol0_nvfs10_gvol0/gsyncd.log<br>
&gt;doesn&#39;t<br>
&gt;seem to show anything very unusual:<br>
&gt;<br>
&gt;[2020-06-03 02:49:01.992177] I [master(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):1384:process] _GMaster: Entry Time<br>
&gt;Taken<br>
&gt;   MKD=0   MKN=0   LIN=0   SYM=0   REN=0   RMD=0CRE=0   duration=0.0000<br>
&gt;UNL=0<br>
&gt;[2020-06-03 02:49:01.992465] I [master(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):1394:process] _GMaster: Data/Metadata<br>
&gt;Time Taken        SETA=0  SETX=0 <br>
&gt;meta_duration=0.0000data_duration=13.0954<br>
&gt;   DATA=8  XATT=0<br>
&gt;[2020-06-03 02:49:01.992863] I [master(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):1404:process] _GMaster: Batch<br>
&gt;Completed<br>
&gt;changelog_end=1591152508        entry_stime=(1591152352, 0)<br>
&gt;changelog_start=1591152494      stime=(1591152507, 0)  <br>
&gt;duration=13.1077<br>
&gt;     num_changelogs=2        mode=live_changelog<br>
&gt;[2020-06-03 02:49:02.958687] D [repce(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):196:push] RepceClient: call<br>
&gt;19017:139678812452608:1591152542.96 keep_alive({&#39;version&#39;: (1, 0),<br>
&gt;&#39;retval&#39;: 0, &#39;uuid&#39;: &#39;8ee85fae-f3aa-4285-ad48-67a1dc17ed73&#39;, &#39;timeout&#39;:<br>
&gt;1591152662, &#39;volume_mark&#39;: (1583043396, 161632)},) ...<br>
&gt;[2020-06-03 02:49:02.979139] D [repce(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):216:__call__] RepceClient: call<br>
&gt;19017:139678812452608:1591152542.96 keep_alive -&gt; 28<br>
&gt;[2020-06-03 02:49:06.998127] D [master(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):551:crawlwrap] _GMaster: ... crawl<br>
&gt;#114<br>
&gt;done, took 30.180089 seconds<br>
&gt;[2020-06-03 02:49:07.10132] D [repce(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):196:push] RepceClient: call<br>
&gt;19017:139679441716992:1591152547.01 scan() ...<br>
&gt;[2020-06-03 02:49:07.10781] D [repce(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):216:__call__] RepceClient: call<br>
&gt;19017:139679441716992:1591152547.01 scan -&gt; None<br>
&gt;[2020-06-03 02:49:07.10935] D [repce(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):196:push] RepceClient: call<br>
&gt;19017:139679441716992:1591152547.01 getchanges() ...<br>
&gt;[2020-06-03 02:49:07.11579] D [repce(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):216:__call__] RepceClient: call<br>
&gt;19017:139679441716992:1591152547.01 getchanges -&gt;<br>
&gt;[&#39;/var/lib/misc/gluster/gsyncd/gvol0_nvfs10_gvol0/nodirectwritedata-gluster-gvol0/.processing/CHANGELOG.1591152522&#39;]<br>
&gt;[2020-06-03 02:49:07.11720] I [master(worker<br>
&gt;/nodirectwritedata/gluster/gvol0):1470:crawl] _GMaster: slave&#39;s time<br>
&gt;stime=(1591152507, 0)<br>
&gt;<br>
&gt;Am I looking in the right place to find out what that gsyncd.py process<br>
&gt;is<br>
&gt;doing?<br>
&gt;<br>
&gt;<br>
&gt;On Tue, 2 Jun 2020 at 21:58, Sunny Kumar &lt;<a href="mailto:sunkumar@redhat.com" target="_blank">sunkumar@redhat.com</a>&gt; wrote:<br>
&gt;<br>
&gt;&gt; Hi David,<br>
&gt;&gt;<br>
&gt;&gt; You haven&#39;t answered my previous question regarding the type of your<br>
&gt;&gt; workload.<br>
&gt;&gt; ---<br>
&gt;&gt; You can use the below command to enable debug log.<br>
&gt;&gt;<br>
&gt;&gt; `gluster vol geo-rep &lt;mastervol&gt; &lt;slavehost&gt;::&lt;slavevol&gt; config<br>
&gt;log-level<br>
&gt;&gt; DEBUG`<br>
&gt;&gt;<br>
&gt;&gt; and after capturing log again switch back to info mode:<br>
&gt;&gt;<br>
&gt;&gt; `gluster vol geo-rep &lt;mastervol&gt; &lt;slavehost&gt;::&lt;slavevol&gt; config<br>
&gt;log-level<br>
&gt;&gt; INFO`<br>
&gt;&gt;<br>
&gt;&gt; Please share the debug log and geo-rep config to debug further:<br>
&gt;&gt; for config:<br>
&gt;&gt;<br>
&gt;&gt; `gluster vol geo-rep &lt;mastervol&gt; &lt;slavehost&gt;::&lt;slavevol&gt; config`<br>
&gt;&gt;<br>
&gt;&gt; /sunny<br>
&gt;&gt;<br>
&gt;&gt;<br>
&gt;&gt; On Tue, Jun 2, 2020 at 10:18 AM Strahil Nikolov<br>
&gt;&lt;<a href="mailto:hunter86_bg@yahoo.com" target="_blank">hunter86_bg@yahoo.com</a>&gt;<br>
&gt;&gt; wrote:<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Hi David,<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; in which log do you see the entries ?<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; I think I got an explanation why you see the process  only on one<br>
&gt;of the<br>
&gt;&gt; master nodes -  geo-rep session is established from only 1 master<br>
&gt;node  /I<br>
&gt;&gt; hope someone corrects me if I&#39;m wrong/ to one slave node. Thus it<br>
&gt;will be<br>
&gt;&gt; natural to see the high CPU  usage on only 1 master node in your<br>
&gt;situation.<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Do you see anything else  in the :<br>
&gt;&gt; var/log/glusterfs/geo-replication/&lt;logs&gt; (master nodes) or in<br>
&gt;&gt; /var/log/glusterfs/geo-replication-slaves (slaves) that could hint of<br>
&gt;the<br>
&gt;&gt; exact issue. I have  a vague feeling that that python script is<br>
&gt;constantly<br>
&gt;&gt; looping over some data causing the CPU hog.<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Sadly, I can&#39;t find an instruction for increasing the log level of<br>
&gt;the<br>
&gt;&gt; geo rep log .<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Best  Regards,<br>
&gt;&gt; &gt; Strahil  Nikolov<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; На 2 юни 2020 г. 6:14:46 GMT+03:00, David Cunningham &lt;<br>
&gt;&gt; <a href="mailto:dcunningham@voisonics.com" target="_blank">dcunningham@voisonics.com</a>&gt; написа:<br>
&gt;&gt; &gt; &gt;Hi Strahil and Sunny,<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;Thank you for the replies. I checked the gfid on the master and<br>
&gt;slaves<br>
&gt;&gt; &gt; &gt;and<br>
&gt;&gt; &gt; &gt;they are the same. After moving the file away and back again it<br>
&gt;doesn&#39;t<br>
&gt;&gt; &gt; &gt;seem to be having the issue with that file any more.<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;We are still getting higher CPU usage on one of the master nodes<br>
&gt;than<br>
&gt;&gt; &gt; &gt;the<br>
&gt;&gt; &gt; &gt;others. It logs this every few seconds:<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:15.637815] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1384:process] _GMaster: Entry<br>
&gt;Time<br>
&gt;&gt; &gt; &gt;Taken<br>
&gt;&gt; &gt; &gt;   MKD=0   MKN=0   LIN=0   SYM=0   REN=0   RMD=0CRE=0  <br>
&gt;duration=0.0000<br>
&gt;&gt; &gt; &gt;UNL=0<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:15.638010] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1394:process] _GMaster:<br>
&gt;Data/Metadata<br>
&gt;&gt; &gt; &gt;Time Taken        SETA=0  SETX=0<br>
&gt;&gt; &gt; &gt;meta_duration=0.0000data_duration=12.7878<br>
&gt;&gt; &gt; &gt;   DATA=4  XATT=0<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:15.638286] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1404:process] _GMaster: Batch<br>
&gt;&gt; &gt; &gt;Completed<br>
&gt;&gt; &gt; &gt;changelog_end=1591067378        entry_stime=(1591067167, 0)<br>
&gt;&gt; &gt; &gt;changelog_start=1591067364      stime=(1591067377, 0)<br>
&gt;&gt; &gt; &gt;duration=12.8068<br>
&gt;&gt; &gt; &gt;     num_changelogs=2        mode=live_changelog<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:20.658601] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1470:crawl] _GMaster: slave&#39;s<br>
&gt;time<br>
&gt;&gt; &gt; &gt; stime=(1591067377, 0)<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:34.21799] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1954:syncjob] Syncer: Sync Time<br>
&gt;Taken<br>
&gt;&gt; &gt; &gt; duration=0.3826 num_files=8     job=1   return_code=0<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:46.440535] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1384:process] _GMaster: Entry<br>
&gt;Time<br>
&gt;&gt; &gt; &gt;Taken<br>
&gt;&gt; &gt; &gt;   MKD=0   MKN=0   LIN=0   SYM=0   REN=1   RMD=0CRE=2  <br>
&gt;duration=0.1314<br>
&gt;&gt; &gt; &gt;UNL=1<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:46.440809] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1394:process] _GMaster:<br>
&gt;Data/Metadata<br>
&gt;&gt; &gt; &gt;Time Taken        SETA=0  SETX=0<br>
&gt;&gt; &gt; &gt;meta_duration=0.0000data_duration=13.0171<br>
&gt;&gt; &gt; &gt;   DATA=14 XATT=0<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:46.441205] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1404:process] _GMaster: Batch<br>
&gt;&gt; &gt; &gt;Completed<br>
&gt;&gt; &gt; &gt;changelog_end=1591067420        entry_stime=(1591067419, 0)<br>
&gt;&gt; &gt; &gt;changelog_start=1591067392      stime=(1591067419, 0)<br>
&gt;&gt; &gt; &gt;duration=13.0322<br>
&gt;&gt; &gt; &gt;     num_changelogs=3        mode=live_changelog<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:10:51.460925] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1470:crawl] _GMaster: slave&#39;s<br>
&gt;time<br>
&gt;&gt; &gt; &gt; stime=(1591067419, 0)<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:11:04.448913] I [master(worker<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0):1954:syncjob] Syncer: Sync Time<br>
&gt;Taken<br>
&gt;&gt; &gt; &gt;duration=0.3466 num_files=3     job=1   return_code=0<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;Whereas the other master nodes only log this:<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:11:33.886938] I [gsyncd(config-get):308:main]<br>
&gt;&lt;top&gt;:<br>
&gt;&gt; &gt; &gt;Using<br>
&gt;&gt; &gt; &gt;session config file<br>
&gt;&gt; &gt;<br>
&gt;&gt;path=/var/lib/glusterd/geo-replication/gvol0_nvfs10_gvol0/gsyncd.conf<br>
&gt;&gt; &gt; &gt;[2020-06-02 03:11:33.993175] I [gsyncd(status):308:main] &lt;top&gt;:<br>
&gt;Using<br>
&gt;&gt; &gt; &gt;session config file<br>
&gt;&gt; &gt;<br>
&gt;&gt;path=/var/lib/glusterd/geo-replication/gvol0_nvfs10_gvol0/gsyncd.conf<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;Can anyone help with what might cause the high CPU usage on one<br>
&gt;master<br>
&gt;&gt; &gt; &gt;node? The process is this one, and is using 70-100% of CPU:<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;python2<br>
&gt;/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/gsyncd.py<br>
&gt;&gt; &gt; &gt;worker gvol0 nvfs10::gvol0 --feedback-fd 15 --local-path<br>
&gt;&gt; &gt; &gt;/nodirectwritedata/gluster/gvol0 --local-node cafs30<br>
&gt;--local-node-id<br>
&gt;&gt; &gt; &gt;b7521445-ee93-4fed-8ced-6a609fa8c7d4 --slave-id<br>
&gt;&gt; &gt; &gt;cdcdb210-839c-4306-a4dc-e696b165ed17 --rpc-fd 12,11,9,13<br>
&gt;--subvol-num 1<br>
&gt;&gt; &gt; &gt;--resource-remote nvfs30 --resource-remote-id<br>
&gt;&gt; &gt; &gt;1e698ccd-aeec-4ec4-96fe-383da8fc3b78<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;Thank you in advance!<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;On Sat, 30 May 2020 at 20:20, Strahil Nikolov<br>
&gt;&lt;<a href="mailto:hunter86_bg@yahoo.com" target="_blank">hunter86_bg@yahoo.com</a>&gt;<br>
&gt;&gt; &gt; &gt;wrote:<br>
&gt;&gt; &gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; Hey David,<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt; &gt;&gt; for me a gfid  mismatch means  that the file  was <br>
&gt;replaced/recreated<br>
&gt;&gt; &gt; &gt; -<br>
&gt;&gt; &gt; &gt;&gt; just like  vim in linux does (and it is expected for config<br>
&gt;file).<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt; &gt;&gt; Have  you checked the gfid  of  the file on both source and<br>
&gt;&gt; &gt; &gt;destination,<br>
&gt;&gt; &gt; &gt;&gt; do they really match or they are different ?<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt; &gt;&gt; What happens  when you move away the file  from the slave , <br>
&gt;does it<br>
&gt;&gt; &gt; &gt;fixes<br>
&gt;&gt; &gt; &gt;&gt; the issue ?<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt; &gt;&gt; Best Regards,<br>
&gt;&gt; &gt; &gt;&gt; Strahil Nikolov<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt; &gt;&gt; На 30 май 2020 г. 1:10:56 GMT+03:00, David Cunningham &lt;<br>
&gt;&gt; &gt; &gt;&gt; <a href="mailto:dcunningham@voisonics.com" target="_blank">dcunningham@voisonics.com</a>&gt; написа:<br>
&gt;&gt; &gt; &gt;&gt; &gt;Hello,<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;We&#39;re having an issue with a geo-replication process with<br>
&gt;unusually<br>
&gt;&gt; &gt; &gt;&gt; &gt;high<br>
&gt;&gt; &gt; &gt;&gt; &gt;CPU use and giving &quot;Entry not present on master. Fixing gfid<br>
&gt;&gt; &gt; &gt;mismatch<br>
&gt;&gt; &gt; &gt;&gt; &gt;in<br>
&gt;&gt; &gt; &gt;&gt; &gt;slave&quot; errors. Can anyone help on this?<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;We have 3 GlusterFS replica nodes (we&#39;ll call the master),<br>
&gt;which<br>
&gt;&gt; &gt; &gt;also<br>
&gt;&gt; &gt; &gt;&gt; &gt;push<br>
&gt;&gt; &gt; &gt;&gt; &gt;data to a remote server (slave) using geo-replication. This has<br>
&gt;been<br>
&gt;&gt; &gt; &gt;&gt; &gt;running fine for a couple of months, but yesterday one of the<br>
&gt;master<br>
&gt;&gt; &gt; &gt;&gt; &gt;nodes<br>
&gt;&gt; &gt; &gt;&gt; &gt;started having unusually high CPU use. It&#39;s this process:<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;root@cafs30:/var/log/glusterfs# ps aux | grep 32048<br>
&gt;&gt; &gt; &gt;&gt; &gt;root     32048 68.7  0.6 1843140 845756 ?      Rl   02:51<br>
&gt;493:51<br>
&gt;&gt; &gt; &gt;&gt; &gt;python2<br>
&gt;&gt; &gt; &gt;&gt; &gt;/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/gsyncd.py<br>
&gt;&gt; &gt; &gt;worker<br>
&gt;&gt; &gt; &gt;&gt; &gt;gvol0 nvfs10::gvol0 --feedback-fd 15 --local-path<br>
&gt;&gt; &gt; &gt;&gt; &gt;/nodirectwritedata/gluster/gvol0 --local-node cafs30<br>
&gt;--local-node-id<br>
&gt;&gt; &gt; &gt;&gt; &gt;b7521445-ee93-4fed-8ced-6a609fa8c7d4 --slave-id<br>
&gt;&gt; &gt; &gt;&gt; &gt;cdcdb210-839c-4306-a4dc-e696b165ed17 --rpc-fd 12,11,9,13<br>
&gt;&gt; &gt; &gt;--subvol-num 1<br>
&gt;&gt; &gt; &gt;&gt; &gt;--resource-remote nvfs30 --resource-remote-id<br>
&gt;&gt; &gt; &gt;&gt; &gt;1e698ccd-aeec-4ec4-96fe-383da8fc3b78<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;Here&#39;s what is being logged in<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt;/var/log/glusterfs/geo-replication/gvol0_nvfs10_gvol0/gsyncd.log:<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:18.843524] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt; &gt;/nodirectwritedata/gluster/gvol0):1470:crawl] _GMaster: slave&#39;s<br>
&gt;time<br>
&gt;&gt; &gt; &gt;&gt; &gt; stime=(1590789408, 0)<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:30.626172] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt;/nodirectwritedata/gluster/gvol0):813:fix_possible_entry_failures]<br>
&gt;&gt; &gt; &gt;&gt; &gt;_GMaster: Entry not present on master. Fixing gfid mismatch in<br>
&gt;&gt; &gt; &gt;slave.<br>
&gt;&gt; &gt; &gt;&gt; &gt;Deleting the entry    retry_count=1   entry=({u&#39;uid&#39;: 108,<br>
&gt;u&#39;gfid&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;7c0b75e5-d8b7-454f-8010-112d613c599e&#39;, u&#39;gid&#39;: 117, u&#39;mode&#39;:<br>
&gt;&gt; &gt; &gt;33204,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;entry&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;.gfid/c5422396-1578-4b50-a29d-315be2a9c5d8/00a859f7xxxx.cfg&#39;,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;op&#39;: u&#39;CREATE&#39;}, 17, {u&#39;slave_isdir&#39;: False,<br>
&gt;u&#39;gfid_mismatch&#39;:<br>
&gt;&gt; &gt; &gt;True,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;slave_name&#39;: None, u&#39;slave_gfid&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;ec4b0ace-2ec4-4ea5-adbc-9f519b81917c&#39;, u&#39;name_mismatch&#39;:<br>
&gt;False,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;dst&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;False})<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:30.627893] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt;/nodirectwritedata/gluster/gvol0):813:fix_possible_entry_failures]<br>
&gt;&gt; &gt; &gt;&gt; &gt;_GMaster: Entry not present on master. Fixing gfid mismatch in<br>
&gt;&gt; &gt; &gt;slave.<br>
&gt;&gt; &gt; &gt;&gt; &gt;Deleting the entry    retry_count=1   entry=({u&#39;uid&#39;: 108,<br>
&gt;u&#39;gfid&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;a4d52e40-2e2f-4885-be5f-65fe95a8ebd7&#39;, u&#39;gid&#39;: 117, u&#39;mode&#39;:<br>
&gt;&gt; &gt; &gt;33204,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;entry&#39;:<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt;<br>
&gt;&gt;&gt;u&#39;.gfid/f857c42e-22f1-4ce4-8f2e-13bdadedde45/polycom_00a859f7xxxx.cfg&#39;,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;op&#39;: u&#39;CREATE&#39;}, 17, {u&#39;slave_isdir&#39;: False,<br>
&gt;u&#39;gfid_mismatch&#39;:<br>
&gt;&gt; &gt; &gt;True,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;slave_name&#39;: None, u&#39;slave_gfid&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;ece8da77-b5ea-45a7-9af7-7d4d8f55f74a&#39;, u&#39;name_mismatch&#39;:<br>
&gt;False,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;dst&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;False})<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:30.629532] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt;/nodirectwritedata/gluster/gvol0):813:fix_possible_entry_failures]<br>
&gt;&gt; &gt; &gt;&gt; &gt;_GMaster: Entry not present on master. Fixing gfid mismatch in<br>
&gt;&gt; &gt; &gt;slave.<br>
&gt;&gt; &gt; &gt;&gt; &gt;Deleting the entry    retry_count=1   entry=({u&#39;uid&#39;: 108,<br>
&gt;u&#39;gfid&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;3c525ad8-aeb2-46b6-9c41-7fb4987916f8&#39;, u&#39;gid&#39;: 117, u&#39;mode&#39;:<br>
&gt;&gt; &gt; &gt;33204,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;entry&#39;:<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt;<br>
&gt;&gt;<br>
&gt;&gt;&gt;u&#39;.gfid/f857c42e-22f1-4ce4-8f2e-13bdadedde45/00a859f7xxxx-directory.xml&#39;,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;op&#39;: u&#39;CREATE&#39;}, 17, {u&#39;slave_isdir&#39;: False,<br>
&gt;u&#39;gfid_mismatch&#39;:<br>
&gt;&gt; &gt; &gt;True,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;slave_name&#39;: None, u&#39;slave_gfid&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;06717b5a-d842-495d-bd25-aab9cd454490&#39;, u&#39;name_mismatch&#39;:<br>
&gt;False,<br>
&gt;&gt; &gt; &gt;&gt; &gt;u&#39;dst&#39;:<br>
&gt;&gt; &gt; &gt;&gt; &gt;False})<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:30.659123] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt; &gt;/nodirectwritedata/gluster/gvol0):942:handle_entry_failures]<br>
&gt;&gt; &gt; &gt;_GMaster:<br>
&gt;&gt; &gt; &gt;&gt; &gt;Sucessfully fixed entry ops with gfid mismatch    <br>
&gt;retry_count=1<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:30.659343] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt; &gt;/nodirectwritedata/gluster/gvol0):1194:process_change]<br>
&gt;_GMaster:<br>
&gt;&gt; &gt; &gt;Retry<br>
&gt;&gt; &gt; &gt;&gt; &gt;original entries. count = 1<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:30.725810] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt; &gt;/nodirectwritedata/gluster/gvol0):1197:process_change]<br>
&gt;_GMaster:<br>
&gt;&gt; &gt; &gt;&gt; &gt;Sucessfully fixed all entry ops with gfid mismatch<br>
&gt;&gt; &gt; &gt;&gt; &gt;[2020-05-29 21:57:31.747319] I [master(worker<br>
&gt;&gt; &gt; &gt;&gt; &gt;/nodirectwritedata/gluster/gvol0):1954:syncjob] Syncer: Sync<br>
&gt;Time<br>
&gt;&gt; &gt; &gt;Taken<br>
&gt;&gt; &gt; &gt;&gt; &gt;duration=0.7409 num_files=18    job=1   return_code=0<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;We&#39;ve verified that the files like polycom_00a859f7xxxx.cfg<br>
&gt;referred<br>
&gt;&gt; &gt; &gt;to<br>
&gt;&gt; &gt; &gt;&gt; &gt;in<br>
&gt;&gt; &gt; &gt;&gt; &gt;the error do exist on the master nodes and slave.<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;We found this bug fix:<br>
&gt;&gt; &gt; &gt;&gt; &gt;<a href="https://bugzilla.redhat.com/show_bug.cgi?id=1642865" rel="noreferrer" target="_blank">https://bugzilla.redhat.com/show_bug.cgi?id=1642865</a><br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;However that fix went in 5.1, and we&#39;re running 5.12 on the<br>
&gt;master<br>
&gt;&gt; &gt; &gt;&gt; &gt;nodes<br>
&gt;&gt; &gt; &gt;&gt; &gt;and slave. A couple of GlusterFS clients connected to the<br>
&gt;master<br>
&gt;&gt; &gt; &gt;nodes<br>
&gt;&gt; &gt; &gt;&gt; &gt;are<br>
&gt;&gt; &gt; &gt;&gt; &gt;running 5.13.<br>
&gt;&gt; &gt; &gt;&gt; &gt;<br>
&gt;&gt; &gt; &gt;&gt; &gt;Would anyone have any suggestions? Thank you in advance.<br>
&gt;&gt; &gt; &gt;&gt;<br>
&gt;&gt; &gt; ________<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Community Meeting Calendar:<br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Schedule -<br>
&gt;&gt; &gt; Every 2nd and 4th Tuesday at 14:30 IST / 09:00 UTC<br>
&gt;&gt; &gt; Bridge: <a href="https://bluejeans.com/441850968" rel="noreferrer" target="_blank">https://bluejeans.com/441850968</a><br>
&gt;&gt; &gt;<br>
&gt;&gt; &gt; Gluster-users mailing list<br>
&gt;&gt; &gt; <a href="mailto:Gluster-users@gluster.org" target="_blank">Gluster-users@gluster.org</a><br>
&gt;&gt; &gt; <a href="https://lists.gluster.org/mailman/listinfo/gluster-users" rel="noreferrer" target="_blank">https://lists.gluster.org/mailman/listinfo/gluster-users</a><br>
&gt;&gt;<br>
&gt;&gt;<br>
</blockquote></div><br clear="all"><br>-- <br><div dir="ltr" class="gmail_signature"><div dir="ltr"><div><div dir="ltr"><div><div dir="ltr"><div><div dir="ltr"><div><div dir="ltr"><div>David Cunningham, Voisonics Limited<br><a href="http://voisonics.com/" target="_blank">http://voisonics.com/</a><br>USA: +1 213 221 1092<br>New Zealand: +64 (0)28 2558 3782</div></div></div></div></div></div></div></div></div></div></div>