libflash: Adding debugging output

Also add usage text to pflash.

Signed-off-by: Cyril Bur <cyril.bur@au1.ibm.com>
Reviewed-by: Samuel Mendoza-Jonas <sam@mendozajonas.com>
Signed-off-by: Stewart Smith <stewart@linux.vnet.ibm.com>

5 files changed, 77 insertions, 21 deletions

diff --git a/libflash/blocklevel.c b/libflash/blocklevel.c
index 9802ad0..d2b7eaa 100644
--- a/libflash/blocklevel.c
+++ b/libflash/blocklevel.c
@@ -82,6 +82,7 @@ int blocklevel_raw_read(struct blocklevel_device *bl, uint64_t pos, void *buf, u
 {
 	int rc;
 
+	FL_DBG("%s: 0x%" PRIx64 "\t%p\t0x%" PRIx64 "\n", __func__, pos, buf, len);
 	if (!bl || !bl->read || !buf) {
 		errno = EINVAL;
 		return FLASH_ERR_PARM_ERROR;
@@ -104,6 +105,7 @@ int blocklevel_read(struct blocklevel_device *bl, uint64_t pos, void *buf, uint6
 	struct ecc64 *buffer;
 	uint64_t ecc_len = ecc_buffer_size(len);
 
+	FL_DBG("%s: 0x%" PRIx64 "\t%p\t0x%" PRIx64 "\n", __func__, pos, buf, len);
 	if (!bl || !buf) {
 		errno = EINVAL;
 		return FLASH_ERR_PARM_ERROR;
@@ -112,6 +114,7 @@ int blocklevel_read(struct blocklevel_device *bl, uint64_t pos, void *buf, uint6
 	if (!ecc_protected(bl, pos, len))
 		return blocklevel_raw_read(bl, pos, buf, len);
 
+	FL_DBG("%s: region has ECC\n", __func__);
 	buffer = malloc(ecc_len);
 	if (!buffer) {
 		errno = ENOMEM;
@@ -138,6 +141,7 @@ int blocklevel_raw_write(struct blocklevel_device *bl, uint64_t pos,
 {
 	int rc;
 
+	FL_DBG("%s: 0x%" PRIx64 "\t%p\t0x%" PRIx64 "\n", __func__, pos, buf, len);
 	if (!bl || !bl->write || !buf) {
 		errno = EINVAL;
 		return FLASH_ERR_PARM_ERROR;
@@ -161,6 +165,7 @@ int blocklevel_write(struct blocklevel_device *bl, uint64_t pos, const void *buf
 	struct ecc64 *buffer;
 	uint64_t ecc_len = ecc_buffer_size(len);
 
+	FL_DBG("%s: 0x%" PRIx64 "\t%p\t0x%" PRIx64 "\n", __func__, pos, buf, len);
 	if (!bl || !buf) {
 		errno = EINVAL;
 		return FLASH_ERR_PARM_ERROR;
@@ -169,6 +174,7 @@ int blocklevel_write(struct blocklevel_device *bl, uint64_t pos, const void *buf
 	if (!ecc_protected(bl, pos, len))
 		return blocklevel_raw_write(bl, pos, buf, len);
 
+	FL_DBG("%s: region has ECC\n", __func__);
 	buffer = malloc(ecc_len);
 	if (!buffer) {
 		errno = ENOMEM;
@@ -197,14 +203,17 @@ int blocklevel_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t len)
 		return FLASH_ERR_PARM_ERROR;
 	}
 
+	FL_DBG("%s: 0x%" PRIx64 "\t0x%" PRIx64 "\n", __func__, pos, len);
+
 	/* Programmer may be making a horrible mistake without knowing it */
 	if (pos & bl->erase_mask) {
-		fprintf(stderr, "blocklevel_erase: pos (0x%"PRIx64") is not erase block (0x%08x) aligned\n",
+		FL_ERR("blocklevel_erase: pos (0x%"PRIx64") is not erase block (0x%08x) aligned\n",
 				pos, bl->erase_mask + 1);
+		return FLASH_ERR_ERASE_BOUNDARY;
 	}
 
 	if (len & bl->erase_mask) {
-		fprintf(stderr, "blocklevel_erase: len (0x%"PRIx64") is not erase block (0x%08x) aligned\n",
+		FL_ERR("blocklevel_erase: len (0x%"PRIx64") is not erase block (0x%08x) aligned\n",
 				len, bl->erase_mask + 1);
 		return FLASH_ERR_ERASE_BOUNDARY;
 	}
@@ -238,7 +247,7 @@ int blocklevel_get_info(struct blocklevel_device *bl, const char **name, uint64_
 
 	/* Check the validity of what we are being told */
 	if (erase_granule && *erase_granule != bl->erase_mask + 1)
-		fprintf(stderr, "blocklevel_get_info: WARNING: erase_granule (0x%08x) and erase_mask"
+		FL_ERR("blocklevel_get_info: WARNING: erase_granule (0x%08x) and erase_mask"
 				" (0x%08x) don't match\n", *erase_granule, bl->erase_mask + 1);
 
 	release(bl);
@@ -286,10 +295,14 @@ int blocklevel_smart_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t
 		return FLASH_ERR_PARM_ERROR;
 	}
 
+	FL_DBG("%s: 0x%" PRIx64 "\t0x%" PRIx64 "\n", __func__, pos, len);
+
 	/* Nothing smart needs to be done, pos and len are aligned */
-	if ((pos & bl->erase_mask) == 0 && (len & bl->erase_mask) == 0)
+	if ((pos & bl->erase_mask) == 0 && (len & bl->erase_mask) == 0) {
+		FL_DBG("%s: Skipping smarts everything is aligned 0x%" PRIx64 " 0x%" PRIx64
+				"to 0x%08x\n", __func__, pos, len, bl->erase_mask);
 		return blocklevel_erase(bl, pos, len);
-
+	}
 	block_size = bl->erase_mask + 1;
 	erase_buf = malloc(block_size);
 	if (!erase_buf) {
@@ -311,6 +324,9 @@ int blocklevel_smart_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t
 		uint64_t base_pos = pos & ~(bl->erase_mask);
 		uint64_t base_len = pos - base_pos;
 
+		FL_DBG("%s: preserving 0x%" PRIx64 "..0x%" PRIx64 "\n",
+				__func__, base_pos, base_pos + base_len);
+
 		/*
 		 * Read the entire block in case this is the ONLY block we're
 		 * modifying, we may need the end chunk of it later
@@ -334,6 +350,8 @@ int blocklevel_smart_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t
 		if (base_pos + base_len + len < base_pos + block_size) {
 			rc = bl->write(bl, pos + len, erase_buf + pos + len,
 					block_size - base_len - len);
+			FL_DBG("%s: Early exit, everything was in one erase block\n",
+					__func__);
 			goto out;
 		}
 
@@ -343,6 +361,8 @@ int blocklevel_smart_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t
 
 	/* Now we should be aligned, best to double check */
 	if (pos & bl->erase_mask) {
+		FL_DBG("%s:pos 0x%" PRIx64 " isn't erase_mask 0x%08x aligned\n",
+			   	__func__, pos, bl->erase_mask);
 		rc = FLASH_ERR_PARM_ERROR;
 		goto out;
 	}
@@ -358,6 +378,8 @@ int blocklevel_smart_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t
 
 	/* Length should be less than a block now */
 	if (len > block_size) {
+		FL_DBG("%s: len 0x%" PRIx64 " is still exceeds block_size 0x%" PRIx64 "\n",
+				__func__, len, block_size);
 		rc = FLASH_ERR_PARM_ERROR;
 		goto out;
 	}
@@ -371,6 +393,9 @@ int blocklevel_smart_erase(struct blocklevel_device *bl, uint64_t pos, uint64_t
 		uint64_t top_pos = pos + len;
 		uint64_t top_len = block_size - len;
 
+		FL_DBG("%s: preserving 0x%" PRIx64 "..0x%" PRIx64 "\n",
+				__func__, top_pos, top_pos + top_len);
+
 		rc = bl->read(bl, top_pos, erase_buf, top_len);
 		if (rc)
 			goto out;
@@ -403,14 +428,20 @@ int blocklevel_smart_write(struct blocklevel_device *bl, uint64_t pos, const voi
 		return FLASH_ERR_PARM_ERROR;
 	}
 
-	if (!(bl->flags & WRITE_NEED_ERASE))
+	FL_DBG("%s: 0x%" PRIx64 "\t0x%" PRIx64 "\n", __func__, pos, len);
+
+	if (!(bl->flags & WRITE_NEED_ERASE)) {
+		FL_DBG("%s: backend doesn't need erase\n", __func__);
 		return blocklevel_write(bl, pos, buf, len);
+	}
 
 	rc = blocklevel_get_info(bl, NULL, NULL, &erase_size);
 	if (rc)
 		return rc;
 
 	if (ecc_protected(bl, pos, len)) {
+		FL_DBG("%s: region has ECC\n", __func__);
+
 		len = ecc_buffer_size(len);
 
 		write_buf_start = malloc(len);
@@ -454,9 +485,15 @@ int blocklevel_smart_write(struct blocklevel_device *bl, uint64_t pos, const voi
 			goto out;
 
 		cmp = blocklevel_flashcmp(erase_buf + block_offset, write_buf, size);
+		FL_DBG("%s: region 0x%08x..0x%08x ", __func__,
+				erase_block, erase_size);
 		if (cmp != 0) {
-			if (cmp == -1)
+			FL_DBG("needs ");
+			if (cmp == -1) {
+				FL_DBG("erase and ");
 				bl->erase(bl, erase_block, erase_size);
+			}
+			FL_DBG("write\n");
 			memcpy(erase_buf + block_offset, write_buf, size);
 			rc = bl->write(bl, erase_block, erase_buf, erase_size);
 			if (rc)
@@ -494,11 +531,13 @@ static bool insert_bl_prot_range(struct blocklevel_range *ranges, struct bl_prot
 	for (i = 0; i < ranges->n_prot && len > 0; i++) {
 		if (prot[i].start <= pos && prot[i].start + prot[i].len >= pos + len) {
 			len = 0;
+			FL_DBG("%s: breaking early\n", __func__);
 			break; /* Might as well, the next two conditions can't be true */
 		}
 
 		/* Can easily extend this down just by adjusting start */
 		if (pos <= prot[i].start && pos + len >= prot[i].start) {
+			FL_DBG("%s: extending start down\n", __func__);
 			prot[i].len += prot[i].start - pos;
 			prot[i].start = pos;
 			pos += prot[i].len;
@@ -513,10 +552,13 @@ static bool insert_bl_prot_range(struct blocklevel_range *ranges, struct bl_prot
 		 * theres a chunk after
 		 */
 		if (pos >= prot[i].start && pos < prot[i].start + prot[i].len) {
+			FL_DBG("%s: fits within current range ", __func__);
 			if (prot[i].start + prot[i].len - pos > len) {
+				FL_DBG("but there is some extra at the end\n");
 				len -= prot[i].start + prot[i].len - pos;
 				pos = prot[i].start + prot[i].len;
 			} else {
+				FL_DBG("\n");
 				len = 0;
 			}
 		}
@@ -531,6 +573,9 @@ static bool insert_bl_prot_range(struct blocklevel_range *ranges, struct bl_prot
 	if (len) {
 		int insert_pos = i;
 		struct bl_prot_range *new_ranges = ranges->prot;
+
+		FL_DBG("%s: adding 0x%08x..0x%08x\n", __func__, pos, pos + len);
+
 		if (ranges->n_prot == ranges->total_prot) {
 			new_ranges = realloc(ranges->prot,
 					sizeof(range) * ((ranges->n_prot) + PROT_REALLOC_NUM));
@@ -550,10 +595,15 @@ static bool insert_bl_prot_range(struct blocklevel_range *ranges, struct bl_prot
 
 	/* Probably only worth mergeing when we're low on space */
 	if (ranges->n_prot + 1 == ranges->total_prot) {
+		FL_DBG("%s: merging ranges\n", __func__);
 		/* Check to see if we can merge ranges */
 		for (i = 0; i < ranges->n_prot - 1; i++) {
 			if (prot[i].start + prot[i].len == prot[i + 1].start) {
 				int j;
+				FL_DBG("%s: merging 0x%" PRIx64 "..0x%" PRIx64 " with "
+						"0x%" PRIx64 "..0x%" PRIx64 "\n",
+						__func__, prot[i].start, prot[i].start + prot[i].len,
+						prot[i + 1].start, prot[i + 1].start + prot[i + 1].len);
 				prot[i].len += prot[i + 1].len;
 				for (j = i + 1; j < ranges->n_prot - 1; j++)
 					memcpy(&prot[j] , &prot[j + 1], sizeof(range));
diff --git a/libflash/errors.h b/libflash/errors.h
index 2f56721..d144e09 100644
--- a/libflash/errors.h
+++ b/libflash/errors.h
@@ -34,4 +34,18 @@
 #define FLASH_ERR_DEVICE_GONE	16
 #define FLASH_ERR_AGAIN	17
 
+#ifdef __SKIBOOT__
+#include <skiboot.h>
+#define FL_INF(fmt...) do { prlog(PR_INFO, fmt);  } while(0)
+#define FL_DBG(fmt...) do { prlog(PR_DEBUG, fmt); } while(0)
+#define FL_ERR(fmt...) do { prlog(PR_ERR, fmt);   } while(0)
+#else
+#include <stdio.h>
+extern bool libflash_debug;
+#define FL_DBG(fmt...) do { if (libflash_debug) printf(fmt); } while(0)
+#define FL_INF(fmt...) do { printf(fmt); } while(0)
+#define FL_ERR(fmt...) do { printf(fmt); } while(0)
+#endif
+
+
 #endif /* __LIBFLASH_ERRORS_H */
diff --git a/libflash/libffs.c b/libflash/libffs.c
index 754245f..4f9509b 100644
--- a/libflash/libffs.c
+++ b/libflash/libffs.c
@@ -321,8 +321,11 @@ int ffs_init(uint32_t offset, uint32_t max_size, struct blocklevel_device *bl,
 
 		list_add_tail(&f->hdr.entries, &ent->list);
 		rc = ffs_entry_to_cpu(&f->hdr, ent, &f->cache->entries[i]);
-		if (rc)
+		if (rc) {
+			FL_DBG("FFS: Failed checksum for partition %s\n",
+					f->cache->entries[i].name);
 			goto out;
+		}
 
 		if (mark_ecc && has_ecc(ent)) {
 			rc = blocklevel_ecc_protect(bl, ent->base, ent->size);
diff --git a/libflash/libflash.h b/libflash/libflash.h
index 4fecfe7..ff3a982 100644
--- a/libflash/libflash.h
+++ b/libflash/libflash.h
@@ -28,19 +28,6 @@
  */
 #include <libflash/errors.h>
 
-#ifdef __SKIBOOT__
-#include <skiboot.h>
-#define FL_INF(fmt...) do { prlog(PR_INFO, fmt);  } while(0)
-#define FL_DBG(fmt...) do { prlog(PR_DEBUG, fmt); } while(0)
-#define FL_ERR(fmt...) do { prlog(PR_ERR, fmt);   } while(0)
-#else
-#include <stdio.h>
-extern bool libflash_debug;
-#define FL_DBG(fmt...) do { if (libflash_debug) printf(fmt); } while(0)
-#define FL_INF(fmt...) do { printf(fmt); } while(0)
-#define FL_ERR(fmt...) do { printf(fmt); } while(0)
-#endif
-
 /* Flash chip, opaque */
 struct flash_chip;
 struct spi_flash_ctrl;
diff --git a/libflash/test/test-blocklevel.c b/libflash/test/test-blocklevel.c
index 4dbbb09..cbf7413 100644
--- a/libflash/test/test-blocklevel.c
+++ b/libflash/test/test-blocklevel.c
@@ -27,6 +27,8 @@
 
 #define ERR(fmt...) fprintf(stderr, fmt)
 
+bool libflash_debug;
+
 static int bl_test_bad_read(struct blocklevel_device *bl __unused, uint64_t pos __unused,
 		void *buf __unused, uint64_t len __unused)
 {