[sanlock] branch master updated (b90eaeb -> 672dbb1)

[git repository hosting]

This is an automated email from the git hooks/post-receive script.

teigland pushed a change to branch master
in repository sanlock.

      from  b90eaeb   sanlock: expand access error message
      adds  6501351   sanlock: preserve dblock values when setting shared flag
      adds  f16530a   sanlock: fix detection of shared lease
      adds  933a474   sanlock: fix release interference with paxos
      adds  735781d   sanlock: fix incorrect error from release
      adds  c1d65fd   sanlock: retry ballot when new lver is seen
       new  ab58c89   sanlock: improve log messages in paxos code
       new  c695e1b   sanlock: add a NOWAIT flag for convert
       new  672dbb1   release 3.6.0

The 3 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "adds" were already present in the repository and have only
been added to this reference.


Summary of changes:
 VERSION                |   2 +-
 src/client.c           |   4 +-
 src/cmd.c              |   2 +-
 src/direct.c           |   3 +-
 src/leader.h           |   2 +-
 src/main.c             |   5 +
 src/ondisk.c           |   2 +
 src/paxos_dblock.h     |   8 +
 src/paxos_lease.c      | 462 +++++++++++++++++++++++++++++++++++++++----------
 src/paxos_lease.h      |   4 +
 src/resource.c         | 179 ++++++++++++++-----
 src/resource.h         |   2 +-
 src/sanlock.conf       |   3 +
 src/sanlock_internal.h |   2 +
 src/sanlock_resource.h |   9 +
 15 files changed, 550 insertions(+), 139 deletions(-)

-- 
To stop receiving notification emails like this one, please contact
the administrator of this repository.

[sanlock] 01/03: sanlock: improve log messages in paxos code

[git repository hosting]

This is an automated email from the git hooks/post-receive script.

teigland pushed a commit to branch master
in repository sanlock.

commit ab58c897e547c77721a52c1833cc3865ecaad3b3
Author: David Teigland <teigland(a)redhat.com&gt;
Date:   Mon Nov 20 15:00:54 2017 -0600

    sanlock: improve log messages in paxos code
    
    A lot of messages related to "interesting" conditions
    (which may want later inspection) were being written
    to /var/log/messages.  Change these to be written only
    to sanlock.log or the memory debug buffer.
    
    Log more paxos details so that the behavior of the
    algorithm can be more fully reconstructed.
---
 src/client.c           |   4 +-
 src/main.c             |   5 +
 src/paxos_lease.c      | 333 +++++++++++++++++++++++++++++++++++++++----------
 src/paxos_lease.h      |   1 +
 src/resource.c         |   3 +
 src/sanlock.conf       |   3 +
 src/sanlock_internal.h |   1 +
 7 files changed, 280 insertions(+), 70 deletions(-)

diff --git a/src/client.c b/src/client.c
index 45aa06a..ad78c21 100644
--- a/src/client.c
+++ b/src/client.c
@@ -2014,6 +2014,8 @@ const char *sanlock_strerror(int rv)
 		return "Lease write error in dblock";
 	case SANLK_DBLOCK_MBAL:
 		return "Lease was acquired by another host in current ballot";
+	case SANLK_DBLOCK_LVER:
+		return "Lease was acquired by another host in new ballot";
 	case SANLK_DBLOCK_CHECKSUM:
 		return "Lease checksum error in dblock";
 	case SANLK_LEADER_READ:
@@ -2036,8 +2038,6 @@ const char *sanlock_strerror(int rv)
 		return "Lease num_hosts is incorrect";
 	case SANLK_LEADER_CHECKSUM:
 		return "Lease checksum error in leader";
-	case SANLK_ACQUIRE_LVER:
-		return "Lease leader version is unmatching";
 	case SANLK_ACQUIRE_LOCKSPACE:
 		return "Lease lockspace is not found";
 	case SANLK_ACQUIRE_IDDISK:
diff --git a/src/main.c b/src/main.c
index 13fec0d..0117183 100644
--- a/src/main.c
+++ b/src/main.c
@@ -2351,6 +2351,10 @@ static void read_config_file(void)
 		} else if (!strcmp(str, "renewal_history_size")) {
 			get_val_int(line, &val);
 			com.renewal_history_size = val;
+
+		} else if (!strcmp(str, "paxos_debug_all")) {
+			get_val_int(line, &val);
+			com.paxos_debug_all = val;
 		}
 	}
 
@@ -3215,6 +3219,7 @@ int main(int argc, char *argv[])
 	com.renewal_read_extend_sec_set = 0;
 	com.renewal_read_extend_sec = 0;
 	com.renewal_history_size = DEFAULT_RENEWAL_HISTORY_SIZE;
+	com.paxos_debug_all = 0;
 
 	if (getgrnam("sanlock") && getpwnam("sanlock")) {
 		com.uname = (char *)"sanlock";
diff --git a/src/paxos_lease.c b/src/paxos_lease.c
index 210543f..a1f43e3 100644
--- a/src/paxos_lease.c
+++ b/src/paxos_lease.c
@@ -35,6 +35,22 @@
 uint32_t crc32c(uint32_t crc, uint8_t *data, size_t length);
 int get_rand(int a, int b);
 
+/*
+ * BK_DEBUG_SIZE:  size of buffer to hold ballot debug info,
+ *                 this can't be larger than LOG_STR_LEN 512
+ * BK_STR_SIZE:    the max length of a dblock string for one host
+ * BK_DEBUG_COUNT: the max number of hosts for which we'll copy
+ *                 dblock info
+ *
+ * BK_DEBUG_COUNT * BK_STR_SIZE + extra debug text that comes before
+ * the dblock info needs to be less than BK_DEBUG_SIZE.
+ * Be very careful about increasing BK_DEBUG_COUNT because the use
+ * of strncat depends on it.
+ */
+#define BK_DEBUG_SIZE 512
+#define BK_DEBUG_COUNT 4
+#define BK_STR_SIZE 80
+
 static uint32_t roundup_power_of_two(uint32_t val)
 {
 	val--;
@@ -427,10 +443,13 @@ static int verify_dblock(struct token *token, struct paxos_dblock
*pd, uint32_t
  *                                           host1 fail
  */
 
-static int run_ballot(struct task *task, struct token *token, int num_hosts,
-		      uint64_t next_lver, uint64_t our_mbal,
+static int run_ballot(struct task *task, struct token *token, uint32_t flags,
+		      int num_hosts, uint64_t next_lver, uint64_t our_mbal,
 		      struct paxos_dblock *dblock_out)
 {
+	char bk_debug[BK_DEBUG_SIZE];
+	char bk_str[BK_STR_SIZE];
+	int bk_debug_count;
 	struct paxos_dblock dblock;
 	struct paxos_dblock bk_in;
 	struct paxos_dblock bk_max;
@@ -477,7 +496,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 	 * component is greater than dblock[p].mbal."
 	 */
 
-	log_token(token, "ballot %llu phase1 mbal %llu",
+	log_token(token, "ballot %llu phase1 write mbal %llu",
 		  (unsigned long long)next_lver,
 		  (unsigned long long)our_mbal);
 
@@ -491,6 +510,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 	num_writes = 0;
 
 	for (d = 0; d < num_disks; d++) {
+		/* acquire io: write 1 */
 		rv = write_dblock(task, token, &token->disks[d], token->host_id,
&dblock);
 		if (rv < 0)
 			continue;
@@ -504,6 +524,9 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 		goto out;
 	}
 
+	memset(bk_debug, 0, sizeof(bk_debug));
+	bk_debug_count = 0;
+
 	num_reads = 0;
 
 	for (d = 0; d < num_disks; d++) {
@@ -513,6 +536,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 			continue;
 		memset(iobuf[d], 0, iobuf_len);
 
+		/* acquire io: read 2 */
 		rv = read_iobuf(disk->fd, disk->offset, iobuf[d], iobuf_len, task,
token->io_timeout, NULL);
 		if (rv == SANLK_AIO_TIMEOUT)
 			iobuf[d] = NULL;
@@ -528,6 +552,28 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 			paxos_dblock_in(bk_end, &bk_in);
 			bk = &bk_in;
 
+			if (bk_in.mbal && ((flags & PAXOS_ACQUIRE_DEBUG_ALL) || (bk_in.lver >=
dblock.lver))) {
+				if (bk_debug_count >= BK_DEBUG_COUNT) {
+					log_token(token, "ballot %llu phase1 read %s",
+						  (unsigned long long)next_lver, bk_debug);
+					memset(bk_debug, 0, sizeof(bk_debug));
+					bk_debug_count = 0;
+				}
+
+				memset(bk_str, 0, sizeof(bk_str));
+				snprintf(bk_str, BK_STR_SIZE, "%d:%llu:%llu:%llu:%llu:%llu:%llu:%x,", q,
+					 (unsigned long long)bk_in.mbal,
+					 (unsigned long long)bk_in.bal,
+					 (unsigned long long)bk_in.inp,
+					 (unsigned long long)bk_in.inp2,
+					 (unsigned long long)bk_in.inp3,
+					 (unsigned long long)bk_in.lver,
+					 bk_in.flags);
+				bk_str[BK_STR_SIZE-1] = '\0';
+				strncat(bk_debug, bk_str, BK_STR_SIZE-1);
+				bk_debug_count++;
+			}
+
 			rv = verify_dblock(token, bk, checksum);
 			if (rv < 0)
 				continue;
@@ -538,10 +584,26 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 				continue;
 
 			if (bk->lver > dblock.lver) {
-				/* I don't think this should happen */
-				log_errot(token, "ballot %llu larger1 lver[%d] %llu",
+				log_level(0, token->token_id, NULL, LOG_WARNING,
+					  "ballot %llu abort1 larger lver in bk[%d] %llu:%llu:%llu:%llu:%llu:%llu
"
+					  "our dblock %llu:%llu:%llu:%llu:%llu:%llu",
 					  (unsigned long long)next_lver, q,
-					  (unsigned long long)bk->lver);
+					  (unsigned long long)bk->mbal,
+					  (unsigned long long)bk->bal,
+					  (unsigned long long)bk->inp,
+					  (unsigned long long)bk->inp2,
+					  (unsigned long long)bk->inp3,
+					  (unsigned long long)bk->lver,
+					  (unsigned long long)dblock.mbal,
+					  (unsigned long long)dblock.bal,
+					  (unsigned long long)dblock.inp,
+					  (unsigned long long)dblock.inp2,
+					  (unsigned long long)dblock.inp3,
+					  (unsigned long long)dblock.lver);
+
+				log_token(token, "ballot %llu phase1 read %s",
+					  (unsigned long long)next_lver, bk_debug);
+
 				error = SANLK_DBLOCK_LVER;
 				goto out;
 			}
@@ -549,10 +611,26 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 			/* see "It aborts the ballot" in comment above */
 
 			if (bk->mbal > dblock.mbal) {
-				log_errot(token, "ballot %llu abort1 mbal %llu mbal[%d] %llu",
-					  (unsigned long long)next_lver,
-					  (unsigned long long)our_mbal, q,
-					  (unsigned long long)bk->mbal);
+				log_level(0, token->token_id, NULL, LOG_WARNING,
+					  "ballot %llu abort1 larger mbal in bk[%d] %llu:%llu:%llu:%llu:%llu:%llu
"
+					  "our dblock %llu:%llu:%llu:%llu:%llu:%llu",
+					  (unsigned long long)next_lver, q,
+					  (unsigned long long)bk->mbal,
+					  (unsigned long long)bk->bal,
+					  (unsigned long long)bk->inp,
+					  (unsigned long long)bk->inp2,
+					  (unsigned long long)bk->inp3,
+					  (unsigned long long)bk->lver,
+					  (unsigned long long)dblock.mbal,
+					  (unsigned long long)dblock.bal,
+					  (unsigned long long)dblock.inp,
+					  (unsigned long long)dblock.inp2,
+					  (unsigned long long)dblock.inp3,
+					  (unsigned long long)dblock.lver);
+
+				log_token(token, "ballot %llu phase1 read %s",
+					  (unsigned long long)next_lver, bk_debug);
+
 				error = SANLK_DBLOCK_MBAL;
 				goto out;
 			}
@@ -576,6 +654,9 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 		}
 	}
 
+	log_token(token, "ballot %llu phase1 read %s",
+		  (unsigned long long)next_lver, bk_debug);
+
 	if (!majority_disks(num_disks, num_reads)) {
 		log_errot(token, "ballot %llu dblock read error %d",
 			  (unsigned long long)next_lver, rv);
@@ -614,8 +695,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 	dblock.checksum = 0; /* set after paxos_dblock_out */
 
 	if (bk_max.inp) {
-		/* not a problem, but interesting to see, so use log_error */
-		log_errot(token, "ballot %llu choose bk_max[%d] lver %llu mbal %llu bal %llu inp
%llu %llu %llu",
+		log_token(token, "ballot %llu choose bk_max[%d] lver %llu mbal %llu bal %llu inp
%llu %llu %llu",
 			  (unsigned long long)next_lver, q_max,
 			  (unsigned long long)bk_max.lver,
 			  (unsigned long long)bk_max.mbal,
@@ -634,7 +714,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 
 	phase2 = 1;
 
-	log_token(token, "ballot %llu phase2 bal %llu inp %llu %llu %llu q_max %d",
+	log_token(token, "ballot %llu phase2 write bal %llu inp %llu %llu %llu q_max
%d",
 		  (unsigned long long)dblock.lver,
 		  (unsigned long long)dblock.bal,
 		  (unsigned long long)dblock.inp,
@@ -645,6 +725,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 	num_writes = 0;
 
 	for (d = 0; d < num_disks; d++) {
+		/* acquire io: write 2 */
 		rv = write_dblock(task, token, &token->disks[d], token->host_id,
&dblock);
 		if (rv < 0)
 			continue;
@@ -658,6 +739,9 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 		goto out;
 	}
 
+	memset(bk_debug, 0, sizeof(bk_debug));
+	bk_debug_count = 0;
+
 	num_reads = 0;
 
 	for (d = 0; d < num_disks; d++) {
@@ -667,6 +751,7 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 			continue;
 		memset(iobuf[d], 0, iobuf_len);
 
+		/* acquire io: read 3 */
 		rv = read_iobuf(disk->fd, disk->offset, iobuf[d], iobuf_len, task,
token->io_timeout, NULL);
 		if (rv == SANLK_AIO_TIMEOUT)
 			iobuf[d] = NULL;
@@ -682,6 +767,28 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 			paxos_dblock_in(bk_end, &bk_in);
 			bk = &bk_in;
 
+			if (bk->mbal && ((flags & PAXOS_ACQUIRE_DEBUG_ALL) || (bk->lver
>= dblock.lver))) {
+				if (bk_debug_count >= BK_DEBUG_COUNT) {
+					log_token(token, "ballot %llu phase2 read %s",
+						  (unsigned long long)next_lver, bk_debug);
+					memset(bk_debug, 0, sizeof(bk_debug));
+					bk_debug_count = 0;
+				}
+
+				memset(bk_str, 0, sizeof(bk_str));
+				snprintf(bk_str, BK_STR_SIZE, "%d:%llu:%llu:%llu:%llu:%llu:%llu:%x,", q,
+					 (unsigned long long)bk->mbal,
+					 (unsigned long long)bk->bal,
+					 (unsigned long long)bk->inp,
+					 (unsigned long long)bk->inp2,
+					 (unsigned long long)bk->inp3,
+					 (unsigned long long)bk->lver,
+					 bk->flags);
+				bk_str[BK_STR_SIZE-1] = '\0';
+				strncat(bk_debug, bk_str, BK_STR_SIZE-1);
+				bk_debug_count++;
+			}
+
 			rv = verify_dblock(token, bk, checksum);
 			if (rv < 0)
 				continue;
@@ -698,22 +805,26 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 				 * also be caught the the bk->mbal > dblock.mbal condition
 				 * below.
 				 */
-				log_errot(token, "ballot %llu larger2 lver[%d] %llu dblock %llu",
-					  (unsigned long long)next_lver, q,
-					  (unsigned long long)bk->lver,
-					  (unsigned long long)dblock.lver);
-				log_errot(token, "ballot %llu larger2 mbal[%d] %llu dblock %llu",
+				log_level(0, token->token_id, NULL, LOG_WARNING,
+					  "ballot %llu abort2 larger lver in bk[%d] %llu:%llu:%llu:%llu:%llu:%llu
"
+					  "our dblock %llu:%llu:%llu:%llu:%llu:%llu",
 					  (unsigned long long)next_lver, q,
 					  (unsigned long long)bk->mbal,
-					  (unsigned long long)dblock.mbal);
-				log_errot(token, "ballot %llu larger2 inp[%d] %llu %llu %llu dblock %llu %llu
%llu",
-					  (unsigned long long)next_lver, q,
+					  (unsigned long long)bk->bal,
 					  (unsigned long long)bk->inp,
 					  (unsigned long long)bk->inp2,
 					  (unsigned long long)bk->inp3,
+					  (unsigned long long)bk->lver,
+					  (unsigned long long)dblock.mbal,
+					  (unsigned long long)dblock.bal,
 					  (unsigned long long)dblock.inp,
 					  (unsigned long long)dblock.inp2,
-					  (unsigned long long)dblock.inp3);
+					  (unsigned long long)dblock.inp3,
+					  (unsigned long long)dblock.lver);
+
+				log_token(token, "ballot %llu phase2 read %s",
+					  (unsigned long long)next_lver, bk_debug);
+
 				error = SANLK_DBLOCK_LVER;
 				goto out;
 			}
@@ -721,16 +832,35 @@ static int run_ballot(struct task *task, struct token *token, int
num_hosts,
 			/* see "It aborts the ballot" in comment above */
 
 			if (bk->mbal > dblock.mbal) {
-				log_errot(token, "ballot %llu abort2 mbal %llu mbal[%d] %llu",
-					  (unsigned long long)next_lver,
-					  (unsigned long long)our_mbal, q,
-					  (unsigned long long)bk->mbal);
+				log_level(0, token->token_id, NULL, LOG_WARNING,
+					  "ballot %llu abort2 larger mbal in bk[%d] %llu:%llu:%llu:%llu:%llu:%llu
"
+					  "our dblock %llu:%llu:%llu:%llu:%llu:%llu",
+					  (unsigned long long)next_lver, q,
+					  (unsigned long long)bk->mbal,
+					  (unsigned long long)bk->bal,
+					  (unsigned long long)bk->inp,
+					  (unsigned long long)bk->inp2,
+					  (unsigned long long)bk->inp3,
+					  (unsigned long long)bk->lver,
+					  (unsigned long long)dblock.mbal,
+					  (unsigned long long)dblock.bal,
+					  (unsigned long long)dblock.inp,
+					  (unsigned long long)dblock.inp2,
+					  (unsigned long long)dblock.inp3,
+					  (unsigned long long)dblock.lver);
+
+				log_token(token, "ballot %llu phase2 read %s",
+					  (unsigned long long)next_lver, bk_debug);
+
 				error = SANLK_DBLOCK_MBAL;
 				goto out;
 			}
 		}
 	}
 
+	log_token(token, "ballot %llu phase2 read %s",
+		  (unsigned long long)next_lver, bk_debug);
+
 	if (!majority_disks(num_disks, num_reads)) {
 		log_errot(token, "ballot %llu dblock read2 error %d",
 			  (unsigned long long)next_lver, rv);
@@ -1115,13 +1245,18 @@ int paxos_lease_leader_read(struct task *task,
 
 static int _lease_read_one(struct task *task,
 			   struct token *token,
+			   uint32_t flags,
 			   struct sync_disk *disk,
 			   struct leader_record *leader_ret,
 			   struct paxos_dblock *our_dblock,
 			   uint64_t *max_mbal,
 			   int *max_q,
-			   const char *caller)
+			   const char *caller,
+			   int log_bk_vals)
 {
+	char bk_debug[BK_DEBUG_SIZE];
+	char bk_str[BK_STR_SIZE];
+	int bk_debug_count;
 	struct leader_record leader_end;
 	struct paxos_dblock our_dblock_end;
 	struct paxos_dblock bk;
@@ -1162,6 +1297,9 @@ static int _lease_read_one(struct task *task,
 	if (rv < 0)
 		goto out;
 
+	memset(bk_debug, 0, sizeof(bk_debug));
+	bk_debug_count = 0;
+
 	for (q = 0; q < leader_ret->num_hosts; q++) {
 		bk_end = (struct paxos_dblock *)(iobuf + ((2 + q) * sector_size));
 
@@ -1169,6 +1307,29 @@ static int _lease_read_one(struct task *task,
 
 		paxos_dblock_in(bk_end, &bk);
 
+		if (log_bk_vals && bk.mbal &&
+		    ((flags & PAXOS_ACQUIRE_DEBUG_ALL) || (bk.lver >= leader_ret->lver))) {
+			if (bk_debug_count >= BK_DEBUG_COUNT) {
+				log_token(token, "leader %llu dblocks %s",
+					  (unsigned long long)leader_ret->lver, bk_debug);
+				memset(bk_debug, 0, sizeof(bk_debug));
+				bk_debug_count = 0;
+			}
+
+			memset(bk_str, 0, sizeof(bk_str));
+			snprintf(bk_str, BK_STR_SIZE, "%d:%llu:%llu:%llu:%llu:%llu:%llu:%x,", q,
+				 (unsigned long long)bk.mbal,
+				 (unsigned long long)bk.bal,
+				 (unsigned long long)bk.inp,
+				 (unsigned long long)bk.inp2,
+				 (unsigned long long)bk.inp3,
+				 (unsigned long long)bk.lver,
+				 bk.flags);
+			bk_str[BK_STR_SIZE-1] = '\0';
+			strncat(bk_debug, bk_str, BK_STR_SIZE-1);
+			bk_debug_count++;
+		}
+
 		rv = verify_dblock(token, &bk, checksum);
 		if (rv < 0)
 			goto out;
@@ -1181,6 +1342,14 @@ static int _lease_read_one(struct task *task,
 	*max_mbal = tmp_mbal;
 	*max_q = tmp_q;
 
+	if (log_bk_vals)
+		log_token(token, "leader %llu owner %llu %llu %llu dblocks %s",
+			  (unsigned long long)leader_ret->lver,
+			  (unsigned long long)leader_ret->owner_id,
+			  (unsigned long long)leader_ret->owner_generation,
+			  (unsigned long long)leader_ret->timestamp,
+			  bk_debug);
+
  out:
 	if (rv != SANLK_AIO_TIMEOUT)
 		free(iobuf);
@@ -1191,6 +1360,7 @@ static int _lease_read_one(struct task *task,
 
 static int _lease_read_num(struct task *task,
 			   struct token *token,
+			   uint32_t flags,
 			   struct leader_record *leader_ret,
 			   struct paxos_dblock *our_dblock,
 			   uint64_t *max_mbal,
@@ -1226,8 +1396,8 @@ static int _lease_read_num(struct task *task,
 	num_reads = 0;
 
 	for (d = 0; d < num_disks; d++) {
-		rv = _lease_read_one(task, token, &token->disks[d], &leader_one,
-				     &dblock_one, &mbal_one, &q_one, caller);
+		rv = _lease_read_one(task, token, flags, &token->disks[d], &leader_one,
+				     &dblock_one, &mbal_one, &q_one, caller, 0);
 		if (rv < 0)
 			continue;
 
@@ -1295,19 +1465,19 @@ static int _lease_read_num(struct task *task,
  * values from it.
  */
 
-static int paxos_lease_read(struct task *task, struct token *token,
+static int paxos_lease_read(struct task *task, struct token *token, uint32_t flags,
 			    struct leader_record *leader_ret,
-			    uint64_t *max_mbal, const char *caller)
+			    uint64_t *max_mbal, const char *caller, int log_bk_vals)
 {
 	struct paxos_dblock our_dblock;
 	int rv, q = -1;
 
 	if (token->r.num_disks > 1)
-		rv = _lease_read_num(task, token,
+		rv = _lease_read_num(task, token, flags,
 				     leader_ret, &our_dblock, max_mbal, &q, caller);
 	else
-		rv = _lease_read_one(task, token, &token->disks[0],
-				     leader_ret, &our_dblock, max_mbal, &q, caller);
+		rv = _lease_read_one(task, token, flags, &token->disks[0],
+				     leader_ret, &our_dblock, max_mbal, &q, caller, log_bk_vals);
 
 	if (rv == SANLK_OK)
 		log_token(token, "%s leader %llu owner %llu %llu %llu max mbal[%d] %llu "
@@ -1415,7 +1585,7 @@ int paxos_lease_acquire(struct task *task,
 	uint64_t max_mbal;
 	uint64_t num_mbal;
 	uint64_t our_mbal;
-	int copy_cur_leader = 0;
+	int copy_cur_leader;
 	int disk_open = 0;
 	int error, rv, us;
 	int other_io_timeout, other_host_dead_seconds;
@@ -1426,8 +1596,11 @@ int paxos_lease_acquire(struct task *task,
 		  flags, (unsigned long long)acquire_lver, new_num_hosts);
 
  restart:
+	memset(&tmp_leader, 0, sizeof(tmp_leader));
+	copy_cur_leader = 0;
 
-	error = paxos_lease_read(task, token, &cur_leader, &max_mbal,
"paxos_acquire");
+	/* acquire io: read 1 */
+	error = paxos_lease_read(task, token, flags, &cur_leader, &max_mbal,
"paxos_acquire", 1);
 	if (error < 0)
 		goto out;
 
@@ -1596,21 +1769,11 @@ int paxos_lease_acquire(struct task *task,
 
 		if ((host_id_leader.timestamp != last_timestamp) ||
 		    (hs.last_live && (hs.last_check == hs.last_live))) {
-			if (flags & PAXOS_ACQUIRE_QUIET_FAIL) {
-				log_token(token, "paxos_acquire owner %llu "
-					  "delta %llu %llu %llu alive",
-					  (unsigned long long)cur_leader.owner_id,
-					  (unsigned long long)host_id_leader.owner_id,
-					  (unsigned long long)host_id_leader.owner_generation,
-					  (unsigned long long)host_id_leader.timestamp);
-			} else {
-				log_errot(token, "paxos_acquire owner %llu "
-					  "delta %llu %llu %llu alive",
-					  (unsigned long long)cur_leader.owner_id,
-					  (unsigned long long)host_id_leader.owner_id,
-					  (unsigned long long)host_id_leader.owner_generation,
-					  (unsigned long long)host_id_leader.timestamp);
-			}
+			log_token(token, "paxos_acquire owner %llu delta %llu %llu %llu alive",
+				  (unsigned long long)cur_leader.owner_id,
+				  (unsigned long long)host_id_leader.owner_id,
+				  (unsigned long long)host_id_leader.owner_generation,
+				  (unsigned long long)host_id_leader.timestamp);
 			memcpy(leader_ret, &cur_leader, sizeof(struct leader_record));
 
 			/* It's possible that the live owner has released the
@@ -1629,7 +1792,8 @@ int paxos_lease_acquire(struct task *task,
 						 cur_leader.owner_id, &owner_dblock);
 				if (!rv && (owner_dblock.flags & DBLOCK_FL_RELEASED)) {
 					/* not an error, but interesting to see */
-					log_errot(token, "paxos_acquire owner %llu %llu %llu writer %llu owner dblock
released",
+					log_level(0, token->token_id, NULL, LOG_WARNING,
+						  "paxos_acquire owner %llu %llu %llu writer %llu owner dblock
released",
 						  (unsigned long long)cur_leader.owner_id,
 						  (unsigned long long)cur_leader.owner_generation,
 						  (unsigned long long)cur_leader.timestamp,
@@ -1684,12 +1848,26 @@ int paxos_lease_acquire(struct task *task,
 			goto out;
 		}
 
+		/*
+		 * In this while loop we are waiting for an indication that the
+		 * current owner is alive or dead, but if we see the leader
+		 * owner change in the meantime, we'll restart the entire
+		 * process.
+		 */
+
 		error = paxos_lease_leader_read(task, token, &tmp_leader,
"paxos_acquire");
 		if (error < 0)
 			goto out;
 
 		if (memcmp(&cur_leader, &tmp_leader, sizeof(struct leader_record))) {
-			log_token(token, "paxos_acquire restart leader changed");
+			log_token(token, "paxos_acquire restart leader changed1 from "
+				  "%llu %llu %llu to %llu %llu %llu",
+				  (unsigned long long)cur_leader.owner_id,
+				  (unsigned long long)cur_leader.owner_generation,
+				  (unsigned long long)cur_leader.timestamp,
+				  (unsigned long long)tmp_leader.owner_id,
+				  (unsigned long long)tmp_leader.owner_generation,
+				  (unsigned long long)tmp_leader.timestamp);
 			goto restart;
 		}
 	}
@@ -1730,6 +1908,7 @@ int paxos_lease_acquire(struct task *task,
 		copy_cur_leader = 0;
 		memcpy(&tmp_leader, &cur_leader, sizeof(struct leader_record));
 	} else {
+		/* acquire io: read 1 (for retry) */
 		error = paxos_lease_leader_read(task, token, &tmp_leader,
"paxos_acquire");
 		if (error < 0)
 			goto out;
@@ -1743,9 +1922,10 @@ int paxos_lease_acquire(struct task *task,
 
 		if (tmp_leader.owner_id == token->host_id &&
 		    tmp_leader.owner_generation == token->host_generation) {
-			/* not a problem, but interesting to see, so use log_error */
+			/* not a problem, but interesting to see */
 
-			log_errot(token, "paxos_acquire %llu owner is our inp "
+			log_level(0, token->token_id, NULL, LOG_WARNING,
+				  "paxos_acquire %llu owner is our inp "
 				  "%llu %llu %llu commited by %llu",
 				  (unsigned long long)next_lver,
 				  (unsigned long long)tmp_leader.owner_id,
@@ -1756,9 +1936,10 @@ int paxos_lease_acquire(struct task *task,
 			memcpy(leader_ret, &tmp_leader, sizeof(struct leader_record));
 			error = SANLK_OK;
 		} else {
-			/* not a problem, but interesting to see, so use log_error */
+			/* not a problem, but interesting to see */
 
-			log_errot(token, "paxos_acquire %llu owner is %llu %llu %llu",
+			log_level(0, token->token_id, NULL, LOG_WARNING,
+				  "paxos_acquire %llu owner is %llu %llu %llu",
 				  (unsigned long long)next_lver,
 				  (unsigned long long)tmp_leader.owner_id,
 				  (unsigned long long)tmp_leader.owner_generation,
@@ -1778,9 +1959,13 @@ int paxos_lease_acquire(struct task *task,
 		 * next_lver is 65, but the current lver on disk is 66, causing us to
 		 * we fail in the larger1 check.)
 		 */
-		log_token(token, "paxos_acquire stale next_lver %llu now %llu owner %llu %llu
%llu",
+		log_token(token, "paxos_acquire %llu restart new lver %llu from "
+			  "%llu %llu %llu to %llu %llu %llu",
 			  (unsigned long long)next_lver,
 			  (unsigned long long)tmp_leader.lver,
+			  (unsigned long long)cur_leader.owner_id,
+			  (unsigned long long)cur_leader.owner_generation,
+			  (unsigned long long)cur_leader.timestamp,
 			  (unsigned long long)tmp_leader.owner_id,
 			  (unsigned long long)tmp_leader.owner_generation,
 			  (unsigned long long)tmp_leader.timestamp);
@@ -1788,21 +1973,26 @@ int paxos_lease_acquire(struct task *task,
 	}
 
 	if (memcmp(&cur_leader, &tmp_leader, sizeof(struct leader_record))) {
-		/* I don't think this should ever happen. */
-		log_errot(token, "paxos_acquire restart leader changed2");
+		log_token(token, "paxos_acquire %llu restart leader changed2 from "
+			  "%llu %llu %llu to %llu %llu %llu",
+			  (unsigned long long)next_lver,
+			  (unsigned long long)cur_leader.owner_id,
+			  (unsigned long long)cur_leader.owner_generation,
+			  (unsigned long long)cur_leader.timestamp,
+			  (unsigned long long)tmp_leader.owner_id,
+			  (unsigned long long)tmp_leader.owner_generation,
+			  (unsigned long long)tmp_leader.timestamp);
 		goto restart;
 	}
 
-	error = run_ballot(task, token, cur_leader.num_hosts, next_lver, our_mbal,
-			   &dblock);
+	error = run_ballot(task, token, flags, cur_leader.num_hosts, next_lver, our_mbal,
&dblock);
 
 	if ((error == SANLK_DBLOCK_MBAL) || (error == SANLK_DBLOCK_LVER)) {
 		us = get_rand(0, 1000000);
 		if (us < 0)
 			us = token->host_id * 100;
 
-		/* not a problem, but interesting to see, so use log_error */
-		log_errot(token, "paxos_acquire %llu retry delay %d us",
+		log_token(token, "paxos_acquire %llu retry delay %d us",
 			  (unsigned long long)next_lver, us);
 
 		usleep(us);
@@ -1858,14 +2048,15 @@ int paxos_lease_acquire(struct task *task,
 	}
 
 	if (new_leader.owner_id != token->host_id) {
-		/* not a problem, but interesting to see, so use log_error */
+		/* not a problem, but interesting to see */
 
 		/* It's possible that we commit an outdated owner id/gen here.
 		   If we go back to the top and retry, we may find that the
 		   owner host_id is alive but with a newer generation, and
 		   we'd be able to get the lease by running the ballot again. */
 
-		log_errot(token, "ballot %llu commit other owner %llu %llu %llu",
+		log_level(0, token->token_id, NULL, LOG_WARNING,
+			  "ballot %llu commit other owner %llu %llu %llu",
 			  (unsigned long long)new_leader.lver,
 			  (unsigned long long)new_leader.owner_id,
 			  (unsigned long long)new_leader.owner_generation,
@@ -1999,6 +2190,14 @@ int paxos_lease_release(struct task *task,
 		return 0;
 	}
 
+	/*
+	 * When we were the writer of our own leader record, then
+	 * releasing the lease includes both setting the REALEASED flag
+	 * in our dblock and clearing out timestamp in the leader.
+	 * When we reread the leader here in release, we should find
+	 * it the same as we last saw in acquire.
+	 */
+
 	if (leader.lver != last->lver) {
 		log_errot(token, "paxos_release other lver "
 			  "last lver %llu owner %llu %llu %llu writer %llu %llu %llu "
@@ -2038,7 +2237,6 @@ int paxos_lease_release(struct task *task,
 			  (unsigned long long)leader.write_id,
 			  (unsigned long long)leader.write_generation,
 			  (unsigned long long)leader.write_timestamp);
-
 		return SANLK_RELEASE_OWNER;
 	}
 
@@ -2061,7 +2259,6 @@ int paxos_lease_release(struct task *task,
 			  (unsigned long long)leader.write_id,
 			  (unsigned long long)leader.write_generation,
 			  (unsigned long long)leader.write_timestamp);
-
 		return SANLK_RELEASE_OWNER;
 	}
 
diff --git a/src/paxos_lease.h b/src/paxos_lease.h
index cce85ed..e2c2484 100644
--- a/src/paxos_lease.h
+++ b/src/paxos_lease.h
@@ -13,6 +13,7 @@
 #define PAXOS_ACQUIRE_QUIET_FAIL	0x00000002
 #define PAXOS_ACQUIRE_SHARED		0x00000004
 #define PAXOS_ACQUIRE_OWNER_NOWAIT	0x00000008
+#define PAXOS_ACQUIRE_DEBUG_ALL		0x00000010
 
 uint32_t leader_checksum(struct leader_record *lr);
 
diff --git a/src/resource.c b/src/resource.c
index 81b6d99..af8f91c 100644
--- a/src/resource.c
+++ b/src/resource.c
@@ -654,6 +654,9 @@ static int acquire_disk(struct task *task, struct token *token,
 	if (com.quiet_fail)
 		flags |= PAXOS_ACQUIRE_QUIET_FAIL;
 
+	if (com.paxos_debug_all)
+		flags |= PAXOS_ACQUIRE_DEBUG_ALL;
+
 	if (token->acquire_flags & SANLK_RES_SHARED)
 		flags |= PAXOS_ACQUIRE_SHARED;
 
diff --git a/src/sanlock.conf b/src/sanlock.conf
index af753d1..4debc6b 100644
--- a/src/sanlock.conf
+++ b/src/sanlock.conf
@@ -43,4 +43,7 @@
 #
 # renewal_read_extend_sec = <seconds>
 # command line: n/a
+#
+# paxos_debug_all = 0
+# command line: n/a
 
diff --git a/src/sanlock_internal.h b/src/sanlock_internal.h
index 5d799b9..4cee6c1 100644
--- a/src/sanlock_internal.h
+++ b/src/sanlock_internal.h
@@ -304,6 +304,7 @@ struct command_line {
 	int debug;
 	int debug_renew;
 	int quiet_fail;
+	int paxos_debug_all;
 	int wait;
 	int use_watchdog;
 	int high_priority;		/* -h */

-- 
To stop receiving notification emails like this one, please contact
the administrator of this repository.

[sanlock] 02/03: sanlock: add a NOWAIT flag for convert

[git repository hosting]

This is an automated email from the git hooks/post-receive script.

teigland pushed a commit to branch master
in repository sanlock.

commit c695e1b2fa09274b10678031dfecbf34f3fa209d
Author: David Teigland <teigland(a)redhat.com&gt;
Date:   Wed Nov 29 14:38:54 2017 -0600

    sanlock: add a NOWAIT flag for convert
    
    Converting sh to ex acquires the paxos lease, like
    a standard acquire.  The caller may want the paxos
    acquire to avoid blocking for convert like acquire.
    
    Don't log an error message for a lock conflict
    in conversion.
---
 src/cmd.c              |  2 +-
 src/resource.c         | 22 ++++++++++++++++------
 src/resource.h         |  2 +-
 src/sanlock_resource.h |  9 +++++++++
 4 files changed, 27 insertions(+), 8 deletions(-)

diff --git a/src/cmd.c b/src/cmd.c
index 453a1b6..c090819 100644
--- a/src/cmd.c
+++ b/src/cmd.c
@@ -922,7 +922,7 @@ static void cmd_convert(struct task *task, struct cmd_args *ca)
 		goto cmd_done;
 	}
 
-	rv = convert_token(task, &res, token);
+	rv = convert_token(task, &res, token, ca->header.cmd_flags);
 	if (rv < 0)
 		result = rv;
 
diff --git a/src/resource.c b/src/resource.c
index af8f91c..05bcc61 100644
--- a/src/resource.c
+++ b/src/resource.c
@@ -1175,10 +1175,12 @@ static struct resource *new_resource(struct token *token)
 	return r;
 }
 
-static int convert_sh2ex_token(struct task *task, struct resource *r, struct token
*token)
+static int convert_sh2ex_token(struct task *task, struct resource *r, struct token
*token,
+			       uint32_t cmd_flags)
 {
 	struct leader_record leader;
 	struct paxos_dblock dblock;
+	uint32_t flags = 0;
 	int live_count = 0;
 	int retries;
 	int error;
@@ -1186,6 +1188,13 @@ static int convert_sh2ex_token(struct task *task, struct resource
*r, struct tok
 
 	memset(&leader, 0, sizeof(leader));
 
+	if (cmd_flags & SANLK_CONVERT_OWNER_NOWAIT)
+		flags |= PAXOS_ACQUIRE_OWNER_NOWAIT;
+	if (com.quiet_fail)
+		flags |= PAXOS_ACQUIRE_QUIET_FAIL;
+	if (com.paxos_debug_all)
+		flags |= PAXOS_ACQUIRE_DEBUG_ALL;
+
 	/* paxos_lease_acquire modifies these token values, and we check them after */
 	token->shared_count = 0;
 	memset(token->shared_bitmap, 0, HOSTID_BITMAP_SIZE);
@@ -1199,12 +1208,12 @@ static int convert_sh2ex_token(struct task *task, struct resource
*r, struct tok
 
 	token->flags |= T_WRITE_DBLOCK_MBLOCK_SH;
 
-	rv = paxos_lease_acquire(task, token, 0, &leader, &dblock, 0, 0);
+	rv = paxos_lease_acquire(task, token, flags, &leader, &dblock, 0, 0);
 
 	token->flags &= ~T_WRITE_DBLOCK_MBLOCK_SH;
 
 	if (rv < 0) {
-		log_errot(token, "convert_sh2ex acquire error %d t_flags %x", rv,
token->flags);
+		log_token(token, "convert_sh2ex acquire error %d t_flags %x", rv,
token->flags);
 
 		/* If the acquire failed before anything important was written,
 		   then this RETRACT flag will not be set, and there is nothing
@@ -1381,7 +1390,8 @@ static int convert_ex2sh_token(struct task *task, struct resource
*r, struct tok
 	return SANLK_OK;
 }
 
-int convert_token(struct task *task, struct sanlk_resource *res, struct token *cl_token)
+int convert_token(struct task *task, struct sanlk_resource *res, struct token *cl_token,
+		  uint32_t cmd_flags)
 {
 	struct resource *r;
 	struct token *tk;
@@ -1451,7 +1461,7 @@ int convert_token(struct task *task, struct sanlk_resource *res,
struct token *c
 	}
 
 	if (!(res->flags & SANLK_RES_SHARED)) {
-		rv = convert_sh2ex_token(task, r, token);
+		rv = convert_sh2ex_token(task, r, token, cmd_flags);
 	} else if (res->flags & SANLK_RES_SHARED) {
 		rv = convert_ex2sh_token(task, r, token);
 	} else {
@@ -1686,7 +1696,7 @@ int acquire_token(struct task *task, struct token *token, uint32_t
cmd_flags,
 	}
 
 	if (rv < 0 && !(token->flags & T_RETRACT_PAXOS)) {
-		log_errot(token, "acquire_token disk error %d", rv);
+		log_token(token, "acquire_token disk error %d", rv);
 		r->flags &= ~R_SHARED;
 		/* zero r->leader means not owned and release will just close */
 		release_token_opened(task, token);
diff --git a/src/resource.h b/src/resource.h
index 9821cfc..70cfd04 100644
--- a/src/resource.h
+++ b/src/resource.h
@@ -27,7 +27,7 @@ int resource_orphan_count(char *space_name);
 void check_mode_block(struct token *token, uint64_t next_lver, int q, char *dblock);
 
 /* locks resource_mutex */
-int convert_token(struct task *task, struct sanlk_resource *res, struct token
*cl_token);
+int convert_token(struct task *task, struct sanlk_resource *res, struct token *cl_token,
uint32_t cmd_flags);
 
 /* locks resource_mutex */
 int acquire_token(struct task *task, struct token *token, uint32_t cmd_flags,
diff --git a/src/sanlock_resource.h b/src/sanlock_resource.h
index d412482..80178d1 100644
--- a/src/sanlock_resource.h
+++ b/src/sanlock_resource.h
@@ -86,6 +86,15 @@
 #define SANLK_REL_ORPHAN	0x00000004
 
 /*
+ * convert flags
+ *
+ * SANLK_CONVERT_OWNER_NOWAIT
+ * Same as SANLK_ACQUIRE_OWNER_NOWAIT.
+ */
+
+#define SANLK_CONVERT_OWNER_NOWAIT	0x00000008 /* NB: value must match
SANLK_ACQUIRE_OWNER_NOWAIT */
+
+/*
  * request flags
  *
  * SANLK_REQUEST_NEXT_LVER

-- 
To stop receiving notification emails like this one, please contact
the administrator of this repository.

[sanlock] 03/03: release 3.6.0

[git repository hosting]

This is an automated email from the git hooks/post-receive script.

teigland pushed a commit to branch master
in repository sanlock.

commit 672dbb1791f82d1d6ee14827839ea7468ac118dc
Author: David Teigland <teigland(a)redhat.com&gt;
Date:   Tue Dec 5 11:17:01 2017 -0600

    release 3.6.0
---
 VERSION | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/VERSION b/VERSION
index 1545d96..40c341b 100644
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-3.5.0
+3.6.0

-- 
To stop receiving notification emails like this one, please contact
the administrator of this repository.