Re: [PATCH 02/45] disk: Drop debug messages in part_efi

[Heinrich Schuchardt <xypron.glpk@gmx.de>]

On 9/25/22 17:02, Simon Glass wrote:
> This is monstrously verbose when something goes wrong. It should work by
> recording the problem and reporting it (once) at the command level. At
> present it sometimes outputs hundreds of lines of CRC mismatches.
>
> For now, just silence it all.
>
>    GUID Partition Table Entry Array CRC is wrong: 0xaebfebf2 != 0xc916f712
>    find_valid_gpt: *** ERROR: Invalid GPT ***
>    find_valid_gpt: ***        Using Backup GPT ***
>    GUID Partition Table Entry Array CRC is wrong: 0xaebfebf2 != 0xc916f712
>    find_valid_gpt: *** ERROR: Invalid GPT ***
>    find_valid_gpt: ***        Using Backup GPT ***
>    ...
>
> Signed-off-by: Simon Glass <sjg@chromium.org>
> ---
>
>   disk/part_efi.c | 148 +++++++++++++++++++++++-------------------------
>   1 file changed, 71 insertions(+), 77 deletions(-)
>
> diff --git a/disk/part_efi.c b/disk/part_efi.c
> index 26738a57d5d..1a359066ae9 100644
> --- a/disk/part_efi.c
> +++ b/disk/part_efi.c
> @@ -94,10 +94,10 @@ static int validate_gpt_header(gpt_header *gpt_h, lbaint_t lba,
>
>   	/* Check the GPT header signature */
>   	if (le64_to_cpu(gpt_h->signature) != GPT_HEADER_SIGNATURE_UBOOT) {
> -		printf("%s signature is wrong: 0x%llX != 0x%llX\n",
> -		       "GUID Partition Table Header",
> -		       le64_to_cpu(gpt_h->signature),
> -		       GPT_HEADER_SIGNATURE_UBOOT);
> +		log_debug("%s signature is wrong: %#llX != %#llX\n",
> +			  "GUID Partition Table Header",
> +			  le64_to_cpu(gpt_h->signature),
> +			  GPT_HEADER_SIGNATURE_UBOOT);
>   		return -1;
>   	}
>
> @@ -111,9 +111,9 @@ static int validate_gpt_header(gpt_header *gpt_h, lbaint_t lba,
>   	memcpy(&gpt_h->header_crc32, &crc32_backup, sizeof(crc32_backup));
>
>   	if (calc_crc32 != le32_to_cpu(crc32_backup)) {
> -		printf("%s CRC is wrong: 0x%x != 0x%x\n",
> -		       "GUID Partition Table Header",
> -		       le32_to_cpu(crc32_backup), calc_crc32);
> +		log_debug("%s: CRC is wrong: %#x != %#x\n",
> +			  "GUID Partition Table Header",
> +			  le32_to_cpu(crc32_backup), calc_crc32);
>   		return -1;
>   	}
>
> @@ -121,9 +121,8 @@ static int validate_gpt_header(gpt_header *gpt_h, lbaint_t lba,
>   	 * Check that the my_lba entry points to the LBA that contains the GPT
>   	 */
>   	if (le64_to_cpu(gpt_h->my_lba) != lba) {
> -		printf("GPT: my_lba incorrect: %llX != " LBAF "\n",
> -		       le64_to_cpu(gpt_h->my_lba),
> -		       lba);
> +		log_debug("GPT: my_lba incorrect: %llX != " LBAF "\n",
> +			  le64_to_cpu(gpt_h->my_lba), lba);
>   		return -1;
>   	}
>
> @@ -132,13 +131,13 @@ static int validate_gpt_header(gpt_header *gpt_h, lbaint_t lba,
>   	 * within the disk.
>   	 */
>   	if (le64_to_cpu(gpt_h->first_usable_lba) > lastlba) {
> -		printf("GPT: first_usable_lba incorrect: %llX > " LBAF "\n",
> -		       le64_to_cpu(gpt_h->first_usable_lba), lastlba);
> +		log_debug("GPT: first_usable_lba incorrect: %llX > " LBAF "\n",
> +			  le64_to_cpu(gpt_h->first_usable_lba), lastlba);
>   		return -1;
>   	}
>   	if (le64_to_cpu(gpt_h->last_usable_lba) > lastlba) {
> -		printf("GPT: last_usable_lba incorrect: %llX > " LBAF "\n",
> -		       le64_to_cpu(gpt_h->last_usable_lba), lastlba);
> +		log_debug("GPT: last_usable_lba incorrect: %llX > " LBAF "\n",
> +			  le64_to_cpu(gpt_h->last_usable_lba), lastlba);
>   		return -1;
>   	}
>
> @@ -159,10 +158,10 @@ static int validate_gpt_entries(gpt_header *gpt_h, gpt_entry *gpt_e)
>   		le32_to_cpu(gpt_h->sizeof_partition_entry));
>
>   	if (calc_crc32 != le32_to_cpu(gpt_h->partition_entry_array_crc32)) {
> -		printf("%s: 0x%x != 0x%x\n",
> -		       "GUID Partition Table Entry Array CRC is wrong",
> -		       le32_to_cpu(gpt_h->partition_entry_array_crc32),
> -		       calc_crc32);
> +		log_debug("%s: %#x != %#x\n",
> +			  "GUID Partition Table Entry Array CRC is wrong",
> +			  le32_to_cpu(gpt_h->partition_entry_array_crc32),
> +			  calc_crc32);
>   		return -1;
>   	}
>
> @@ -330,14 +329,15 @@ static int set_protective_mbr(struct blk_desc *dev_desc)
>   	/* Setup the Protective MBR */
>   	ALLOC_CACHE_ALIGN_BUFFER_PAD(legacy_mbr, p_mbr, 1, dev_desc->blksz);
>   	if (p_mbr == NULL) {
> -		printf("%s: calloc failed!\n", __func__);
> -		return -1;
> +		log_debug("calloc failed!\n");
> +		return -ENOMEM;
>   	}
>
>   	/* Read MBR to backup boot code if it exists */
>   	if (blk_dread(dev_desc, 0, 1, p_mbr) != 1) {
> -		pr_err("** Can't read from device %d **\n", dev_desc->devnum);
> -		return -1;
> +		log_debug("** Can't read from device %d **\n",
> +			  dev_desc->devnum);
> +		return -EIO;
>   	}
>
>   	/* Clear all data in MBR except of backed up boot code */
> @@ -352,9 +352,8 @@ static int set_protective_mbr(struct blk_desc *dev_desc)
>
>   	/* Write MBR sector to the MMC device */
>   	if (blk_dwrite(dev_desc, 0, 1, p_mbr) != 1) {
> -		printf("** Can't write to device %d **\n",
> -			dev_desc->devnum);
> -		return -1;
> +		log_debug("** Can't write to device %d **\n", dev_desc->devnum);
> +		return -EIO;
>   	}
>
>   	return 0;
> @@ -404,8 +403,8 @@ int write_gpt_table(struct blk_desc *dev_desc,
>   	return 0;
>
>    err:
> -	printf("** Can't write to device %d **\n", dev_desc->devnum);
> -	return -1;
> +	log_debug("** Can't write to device %d **\n", dev_desc->devnum);
> +	return -EIO;
>   }
>
>   int gpt_fill_pte(struct blk_desc *dev_desc,
> @@ -451,15 +450,15 @@ int gpt_fill_pte(struct blk_desc *dev_desc,
>   		 */
>   		if (((start < hdr_end && hdr_start < (start + size)) ||
>   		     (start < pte_end && pte_start < (start + size)))) {
> -			printf("Partition overlap\n");
> -			return -1;
> +			log_debug("Partition overlap\n");
> +			return -ENOSPC;
>   		}
>
>   		gpt_e[i].starting_lba = cpu_to_le64(start);
>
>   		if (offset > (last_usable_lba + 1)) {
> -			printf("Partitions layout exceds disk size\n");
> -			return -1;
> +			log_debug("Partitions layout exceeds disk size\n");
> +			return -E2BIG;
>   		}
>   		/* partition ending lba */
>   		if ((i == parts - 1) && (size == 0))
> @@ -474,9 +473,9 @@ int gpt_fill_pte(struct blk_desc *dev_desc,
>   		if (strlen(str_type_guid)) {
>   			if (uuid_str_to_bin(str_type_guid, bin_type_guid,
>   					    UUID_STR_FORMAT_GUID)) {
> -				printf("Partition no. %d: invalid type guid: %s\n",
> -				       i, str_type_guid);
> -				return -1;
> +				log_debug("Partition no. %d: invalid type guid: %s\n",
> +					  i, str_type_guid);
> +				return -EINVAL;
>   			}
>   		} else {
>   			/* default partition type GUID */
> @@ -494,9 +493,9 @@ int gpt_fill_pte(struct blk_desc *dev_desc,
>   		bin_uuid = gpt_e[i].unique_partition_guid.b;
>
>   		if (uuid_str_to_bin(str_uuid, bin_uuid, UUID_STR_FORMAT_GUID)) {
> -			printf("Partition no. %d: invalid guid: %s\n",
> -				i, str_uuid);
> -			return -1;
> +			log_debug("Partition no. %d: invalid guid: %s\n",
> +				  i, str_uuid);
> +			return -EINVAL;
>   		}
>   #endif
>
> @@ -608,8 +607,8 @@ int gpt_restore(struct blk_desc *dev_desc, char *str_disk_guid,
>   	size = PAD_TO_BLOCKSIZE(sizeof(gpt_header), dev_desc);
>   	gpt_h = malloc_cache_aligned(size);
>   	if (gpt_h == NULL) {
> -		printf("%s: calloc failed!\n", __func__);
> -		return -1;
> +		log_debug("calloc failed!\n");
> +		return -ENOMEM;
>   	}
>   	memset(gpt_h, 0, size);
>
> @@ -617,9 +616,9 @@ int gpt_restore(struct blk_desc *dev_desc, char *str_disk_guid,
>   				dev_desc);
>   	gpt_e = malloc_cache_aligned(size);
>   	if (gpt_e == NULL) {
> -		printf("%s: calloc failed!\n", __func__);
> +		log_debug("calloc failed!\n");
>   		free(gpt_h);
> -		return -1;
> +		return -ENOMEM;
>   	}
>   	memset(gpt_e, 0, size);
>
> @@ -675,8 +674,7 @@ int gpt_verify_headers(struct blk_desc *dev_desc, gpt_header *gpt_head,
>   	if (is_gpt_valid(dev_desc,
>   			 GPT_PRIMARY_PARTITION_TABLE_LBA,
>   			 gpt_head, gpt_pte) != 1) {
> -		printf("%s: *** ERROR: Invalid GPT ***\n",
> -		       __func__);
> +		log_debug("*** ERROR: Invalid GPT ***\n");

Silencing the messages during partition probing looks ok to me.

Can we get rid of all these '*** ERROR: '? The message texts already
indicate that an unexpected situation occurred.

Best regards

Heinrich

>   		return -1;
>   	}
>
> @@ -687,15 +685,13 @@ int gpt_verify_headers(struct blk_desc *dev_desc, gpt_header *gpt_head,
>   	 * Check that the alternate_lba entry points to the last LBA
>   	 */
>   	if (le64_to_cpu(gpt_head->alternate_lba) != (dev_desc->lba - 1)) {
> -		printf("%s: *** ERROR: Misplaced Backup GPT ***\n",
> -		       __func__);
> +		log_debug("*** ERROR: Misplaced Backup GPT ***\n");
>   		return -1;
>   	}
>
>   	if (is_gpt_valid(dev_desc, (dev_desc->lba - 1),
>   			 gpt_head, gpt_pte) != 1) {
> -		printf("%s: *** ERROR: Invalid Backup GPT ***\n",
> -		       __func__);
> +		log_debug("*** ERROR: Invalid Backup GPT ***\n");
>   		return -1;
>   	}
>
> @@ -913,8 +909,8 @@ int write_mbr_and_gpt_partitions(struct blk_desc *dev_desc, void *buf)
>   	lba = 0;	/* MBR is always at 0 */
>   	cnt = 1;	/* MBR (1 block) */
>   	if (blk_dwrite(dev_desc, lba, cnt, buf) != cnt) {
> -		printf("%s: failed writing '%s' (%d blks at 0x" LBAF ")\n",
> -		       __func__, "MBR", cnt, lba);
> +		log_debug("failed writing '%s' (%d blks at 0x" LBAF ")\n",
> +			  "MBR", cnt, lba);
>   		return 1;
>   	}
>
> @@ -922,16 +918,16 @@ int write_mbr_and_gpt_partitions(struct blk_desc *dev_desc, void *buf)
>   	lba = GPT_PRIMARY_PARTITION_TABLE_LBA;
>   	cnt = 1;	/* GPT Header (1 block) */
>   	if (blk_dwrite(dev_desc, lba, cnt, gpt_h) != cnt) {
> -		printf("%s: failed writing '%s' (%d blks at 0x" LBAF ")\n",
> -		       __func__, "Primary GPT Header", cnt, lba);
> +		log_debug("failed writing '%s' (%d blks at 0x" LBAF ")\n",
> +			  "Primary GPT Header", cnt, lba);
>   		return 1;
>   	}
>
>   	lba = le64_to_cpu(gpt_h->partition_entry_lba);
>   	cnt = gpt_e_blk_cnt;
>   	if (blk_dwrite(dev_desc, lba, cnt, gpt_e) != cnt) {
> -		printf("%s: failed writing '%s' (%d blks at 0x" LBAF ")\n",
> -		       __func__, "Primary GPT Entries", cnt, lba);
> +		log_debug("failed writing '%s' (%d blks at 0x" LBAF ")\n",
> +			  "Primary GPT Entries", cnt, lba);
>   		return 1;
>   	}
>
> @@ -941,16 +937,16 @@ int write_mbr_and_gpt_partitions(struct blk_desc *dev_desc, void *buf)
>   	lba = le64_to_cpu(gpt_h->partition_entry_lba);
>   	cnt = gpt_e_blk_cnt;
>   	if (blk_dwrite(dev_desc, lba, cnt, gpt_e) != cnt) {
> -		printf("%s: failed writing '%s' (%d blks at 0x" LBAF ")\n",
> -		       __func__, "Backup GPT Entries", cnt, lba);
> +		log_debug("failed writing '%s' (%d blks at 0x" LBAF ")\n",
> +			  "Backup GPT Entries", cnt, lba);
>   		return 1;
>   	}
>
>   	lba = le64_to_cpu(gpt_h->my_lba);
>   	cnt = 1;	/* GPT Header (1 block) */
>   	if (blk_dwrite(dev_desc, lba, cnt, gpt_h) != cnt) {
> -		printf("%s: failed writing '%s' (%d blks at 0x" LBAF ")\n",
> -		       __func__, "Backup GPT Header", cnt, lba);
> +		log_debug("failed writing '%s' (%d blks at 0x" LBAF ")\n",
> +			  "Backup GPT Header", cnt, lba);
>   		return 1;
>   	}
>
> @@ -1017,7 +1013,7 @@ static int is_gpt_valid(struct blk_desc *dev_desc, u64 lba,
>   {
>   	/* Confirm valid arguments prior to allocation. */
>   	if (!dev_desc || !pgpt_head) {
> -		printf("%s: Invalid Argument(s)\n", __func__);
> +		log_debug("Invalid Argument(s)\n");
>   		return 0;
>   	}
>
> @@ -1025,19 +1021,19 @@ static int is_gpt_valid(struct blk_desc *dev_desc, u64 lba,
>
>   	/* Read MBR Header from device */
>   	if (blk_dread(dev_desc, 0, 1, (ulong *)mbr) != 1) {
> -		printf("*** ERROR: Can't read MBR header ***\n");
> +		log_debug("*** ERROR: Can't read MBR header ***\n");
>   		return 0;
>   	}
>
>   	/* Read GPT Header from device */
>   	if (blk_dread(dev_desc, (lbaint_t)lba, 1, pgpt_head) != 1) {
> -		printf("*** ERROR: Can't read GPT header ***\n");
> +		log_debug("*** ERROR: Can't read GPT header ***\n");
>   		return 0;
>   	}
>
>   	/* Invalid but nothing to yell about. */
>   	if (le64_to_cpu(pgpt_head->signature) == GPT_HEADER_CHROMEOS_IGNORE) {
> -		debug("ChromeOS 'IGNOREME' GPT header found and ignored\n");
> +		log_debug("ChromeOS 'IGNOREME' GPT header found and ignored\n");
>   		return 2;
>   	}
>
> @@ -1089,17 +1085,15 @@ static int find_valid_gpt(struct blk_desc *dev_desc, gpt_header *gpt_head,
>
>   	if (r != 1) {
>   		if (r != 2)
> -			printf("%s: *** ERROR: Invalid GPT ***\n", __func__);
> +			log_debug("*** ERROR: Invalid GPT ***\n");
>
>   		if (is_gpt_valid(dev_desc, (dev_desc->lba - 1), gpt_head,
>   				 pgpt_pte) != 1) {
> -			printf("%s: *** ERROR: Invalid Backup GPT ***\n",
> -			       __func__);
> +			log_debug("*** ERROR: Invalid Backup GPT ***\n");
>   			return 0;
>   		}
>   		if (r != 2)
> -			printf("%s: ***        Using Backup GPT ***\n",
> -			       __func__);
> +			log_debug("***        Using Backup GPT ***\n");
>   	}
>   	return 1;
>   }
> @@ -1121,17 +1115,17 @@ static gpt_entry *alloc_read_gpt_entries(struct blk_desc *dev_desc,
>   	gpt_entry *pte = NULL;
>
>   	if (!dev_desc || !pgpt_head) {
> -		printf("%s: Invalid Argument(s)\n", __func__);
> +		log_debug("Invalid Argument(s)\n");
>   		return NULL;
>   	}
>
>   	count = le32_to_cpu(pgpt_head->num_partition_entries) *
>   		le32_to_cpu(pgpt_head->sizeof_partition_entry);
>
> -	debug("%s: count = %u * %u = %lu\n", __func__,
> -	      (u32) le32_to_cpu(pgpt_head->num_partition_entries),
> -	      (u32) le32_to_cpu(pgpt_head->sizeof_partition_entry),
> -	      (ulong)count);
> +	log_debug("count = %u * %u = %lu\n",
> +		  (u32)le32_to_cpu(pgpt_head->num_partition_entries),
> +		  (u32)le32_to_cpu(pgpt_head->sizeof_partition_entry),
> +		  (ulong)count);
>
>   	/* Allocate memory for PTE, remember to FREE */
>   	if (count != 0) {
> @@ -1140,8 +1134,8 @@ static gpt_entry *alloc_read_gpt_entries(struct blk_desc *dev_desc,
>   	}
>
>   	if (count == 0 || pte == NULL) {
> -		printf("%s: ERROR: Can't allocate %#lX bytes for GPT Entries\n",
> -		       __func__, (ulong)count);
> +		log_debug("ERROR: Can't allocate %#lX bytes for GPT Entries\n",
> +			  (ulong)count);
>   		return NULL;
>   	}
>
> @@ -1149,7 +1143,7 @@ static gpt_entry *alloc_read_gpt_entries(struct blk_desc *dev_desc,
>   	blk = le64_to_cpu(pgpt_head->partition_entry_lba);
>   	blk_cnt = BLOCK_CNT(count, dev_desc);
>   	if (blk_dread(dev_desc, blk, (lbaint_t)blk_cnt, pte) != blk_cnt) {
> -		printf("*** ERROR: Can't read GPT Entries ***\n");
> +		log_debug("*** ERROR: Can't read GPT Entries ***\n");
>   		free(pte);
>   		return NULL;
>   	}
> @@ -1167,7 +1161,7 @@ static int is_pte_valid(gpt_entry * pte)
>   	efi_guid_t unused_guid;
>
>   	if (!pte) {
> -		printf("%s: Invalid Argument(s)\n", __func__);
> +		log_debug("Invalid Argument(s)\n");
>   		return 0;
>   	}
>
> @@ -1179,8 +1173,8 @@ static int is_pte_valid(gpt_entry * pte)
>   	if (memcmp(pte->partition_type_guid.b, unused_guid.b,
>   		sizeof(unused_guid.b)) == 0) {
>
> -		debug("%s: Found an unused PTE GUID at 0x%08X\n", __func__,
> -		      (unsigned int)(uintptr_t)pte);
> +		log_debug("Found an unused PTE GUID at 0x%08X\n",
> +			  (unsigned int)(uintptr_t)pte);
>
>   		return 0;
>   	} else {