feature/changelog: Fix for missing changelogs at backend.

Problem:
       A few changelog files are missing at the backend
       during snapshot with changelog enabled.

Cause:
       Race between actual rollover and explicit rollover.

       Changelog rollover can happen either due to actual
       or the explict rollover due to snapshot. Actual
       rollover is controlled by tuneable called rollover-time.
       The minimum granularity for rollover-time is 1 second
       Explicit rollover is asynchronous in nature and happens
       during snapshot.

       Basically, rollover renames the current CHANGELOG file
       to CHANGELOG.TIMESTAMP after rollover-time. Let's assume,
       at time 't1', actual and explicit rollover raced against
       each other and actual rollover won the race renaming the
       CHANGELOG file to CHANGELOG.t1 and opens a new
       CHANGELOG file. An immediate explicit rollover at time
       't1' happened with in the same second to rename
       CHANGELOG file to CHANGELOG.t1 resulting in purging the
       earlier CHANGELOG.t1 file created by actual rollover.

Solution:
       Adding a delay of 1 sec guarantees unique CHANGELOG.TIMESTAMP
       during explicit rollover.

Thanks Venky, for the all the help in root causing the issue.

Change-Id: I8958824e107e16f61be9f09a11d95f8645ecf34d
BUG: 1109692
Signed-off-by: Kotresh H R <khiremat@redhat.com>
Reviewed-on: http://review.gluster.org/8196
Tested-by: Gluster Build System <jenkins@build.gluster.com>
Reviewed-by: Venky Shankar <vshankar@redhat.com>
Tested-by: Venky Shankar <vshankar@redhat.com>

2 files changed, 28 insertions, 4 deletions

diff --git a/xlators/features/changelog/src/changelog-helpers.c b/xlators/features/changelog/src/changelog-helpers.c
index 8efe7dc4695..b271f3f0fc0 100644
--- a/xlators/features/changelog/src/changelog-helpers.c
+++ b/xlators/features/changelog/src/changelog-helpers.c
@@ -253,8 +253,8 @@ changelog_rollover_changelog (xlator_t *this,
                                          CHANGELOG_PTHREAD_ERROR_HANDLE_0 (ret,
                                                                            out);
                                          gf_log (this->name, GF_LOG_INFO,
-                                                 "Changelog published and"
-                                                 " signalled bnotify");
+                                                 "Changelog published: %s and"
+                                                 " signalled bnotify", bname);
                                 }
                                 ret = pthread_mutex_unlock (
                                                        &priv->bn.bnotify_mutex);
@@ -677,6 +677,30 @@ changelog_rollover (void *data)
                         changelog_drain_white_fops (this, priv);
                 }
 
+                /* Adding delay of 1 second only during explicit rollover:
+                 *
+                 * Changelog rollover can happen either due to actual
+                 * or the explict rollover during snapshot. Actual
+                 * rollover is controlled by tuneable called 'rollover-time'.
+                 * The minimum granularity for rollover-time is 1 second.
+                 * Explicit rollover is asynchronous in nature and happens
+                 * during snapshot.
+                 *
+                 * Basically, rollover renames the current CHANGELOG file
+                 * to CHANGELOG.TIMESTAMP. Let's assume, at time 't1',
+                 * actual and explicit rollover raced against  each
+                 * other and actual rollover won the race renaming the
+                 * CHANGELOG file to CHANGELOG.t1 and opens a new
+                 * CHANGELOG file. There is high chance that, an immediate
+                 * explicit rollover at time 't1' can happen with in the same
+                 * second to rename CHANGELOG file to CHANGELOG.t1 resulting in
+                 * purging the earlier CHANGELOG.t1 file created by actual
+                 * rollover. So adding a delay of 1 second guarantees unique
+                 * CHANGELOG.TIMESTAMP during  explicit rollover.
+                 */
+                if (priv->explicit_rollover == _gf_true)
+                        sleep (1);
+
                 ret = changelog_fill_rollover_data (&cld, _gf_false);
                 if (ret) {
                         gf_log (this->name, GF_LOG_ERROR,
diff --git a/xlators/features/changelog/src/changelog.c b/xlators/features/changelog/src/changelog.c
index 43458006d13..bbf05ba48c1 100644
--- a/xlators/features/changelog/src/changelog.c
+++ b/xlators/features/changelog/src/changelog.c
@@ -1499,7 +1499,7 @@ notify (xlator_t *this, int event, void *data, ...)
                          */
                         if (ret == 0) {
                                 chlog_barrier_dequeue_all(this, &queue);
-                                gf_log(this->name, GF_LOG_DEBUG,
+                                gf_log(this->name, GF_LOG_INFO,
                                        "Disabled changelog barrier");
                         } else {
                                 gf_log (this->name, GF_LOG_ERROR,
@@ -1557,7 +1557,7 @@ notify (xlator_t *this, int event, void *data, ...)
                                 goto out;
                         }
 
-                        gf_log(this->name, GF_LOG_DEBUG,
+                        gf_log(this->name, GF_LOG_INFO,
                                            "Enabled changelog barrier");
 
                         ret = changelog_barrier_notify(priv, buf);