[Freeipa-devel] [PATCH 0093] Log memory allocation failures

[Adam Tkac]

On Tue, Nov 20, 2012 at 10:11:42AM +0100, Petr Spacek wrote:
> On 11/19/2012 06:33 PM, Adam Tkac wrote:
> >On Fri, Nov 16, 2012 at 03:15:44PM +0100, Petr Spacek wrote:
> >>On 11/16/2012 02:24 PM, Simo Sorce wrote:
> >>>On Fri, 2012-11-16 at 13:31 +0100, Petr Spacek wrote:
> >>>>+#define FILE_LINE_FUNC_MSG "%-15s: %4d: %-20s"
> >>>>+#define FILE_LINE_FUNC_ARG __FILE__, __LINE__, __func__
> <snip>
> 
> >Thanks for the patch, please read my comments below.
> <snip>
> 
> >>diff --git a/src/log.h b/src/log.h
> >>index 9062a4e80786b5bab806d6c9ceba1d1a9917a3e2..d6a40151d25b6f67cf6735ec955d45e4ebe4106c 100644
> >>--- a/src/log.h
> >>+++ b/src/log.h
> <snip>
> 
> >>+#define log_error_position(format, ...)				\
> >>+	log_error("[%-15s: %4d: %-21s] " format, 			\
> >
> >Do we really need to format the format string? I would prefer to drop the
> >"[...]" stuff at all.
> 
> This format will align file names, line numbers and most of function
> names in columns. It can be handy if some error propagates through
> call stack, but I can drop it if you want.
> 
> Real world example:
> [ldap_entry.c   :  370: ldap_entry_getfakesoa] FAILURE: not found
> [ldap_helper.c  : 1869: add_soa_record       ] FAILURE: not found
> 
> 
> My intention is to extend logging to failures detected inside CHECK() macros.
> 
> Currently, any failure inside CHECK() will jump to "cleanup" label,
> so information about source of the failure is lost.
> 
> As a result it produces error message like:
> update_record (psearch) failed, dn
> 'idnsName=q.sub,idnsname=test,cn=dns,dc=e,dc=test' change type 0x1.
> Records can be outdated, run `rndc reload`: not found
> 
> Huh? What was not found? Those error messages are not useful for
> post mortem analysis.
> 
> With logging inside CHECK() it produces:
> [ldap_helper.c  : 3467: update_record        ] FAILURE: not found
> update_record (psearch) failed, dn
> 'idnsName=q.sub,idnsname=test,cn=dns,dc=e,dc=test' change type 0x1.
> Records can be outdated, run `rndc reload`: not found
> 
> File ldap_helper.c, line 3467, return code ISC_R_NOTFOUND is much
> better information.

Ok, you convinced me.

Ack.

> <snip>
> >>@@ -46,15 +48,17 @@
> >>  		(target_ptr) = isc_mem_allocate((m), (s));	\
> >>  		if ((target_ptr) == NULL) {			\
> >>  			result = ISC_R_NOMEMORY;		\
> >>+			log_error_position("MEMORY ALLOCATION FAILURE");	\
> >
> >Such huge msg is not needed, I think. What about more conservative
> >
> >log_error_position("Memory allocation failed")
> You are right, I shouldn't scream too much. Amended patch is attached.

> From e9e4b8aa38cb612cf39a1e917c74fd0022de6fd4 Mon Sep 17 00:00:00 2001
> From: Petr Spacek <pspacek at redhat.com>
> Date: Fri, 16 Nov 2012 13:17:44 +0100
> Subject: [PATCH] Log memory allocation failures.
> 
> Signed-off-by: Petr Spacek <pspacek at redhat.com>
> ---
>  src/log.h  | 7 ++++++-
>  src/util.h | 5 +++++
>  2 files changed, 11 insertions(+), 1 deletion(-)
> 
> diff --git a/src/log.h b/src/log.h
> index 9062a4e80786b5bab806d6c9ceba1d1a9917a3e2..d6a40151d25b6f67cf6735ec955d45e4ebe4106c 100644
> --- a/src/log.h
> +++ b/src/log.h
> @@ -23,22 +23,27 @@
>  
>  #include <isc/error.h>
>  #include <dns/log.h>
> +#include <dns/result.h>
>  
>  #ifdef LOG_AS_ERROR
>  #define GET_LOG_LEVEL(level)	ISC_LOG_ERROR
>  #else
>  #define GET_LOG_LEVEL(level)	(level)
>  #endif
>  
>  #define fatal_error(...) \
> -    isc_error_fatal(__FILE__, __LINE__, __VA_ARGS__)
> +	isc_error_fatal(__FILE__, __LINE__, __VA_ARGS__)
>  
>  #define log_bug(fmt, ...) \
>  	log_error("bug in %s(): " fmt, __func__,##__VA_ARGS__)
>  
>  #define log_error_r(fmt, ...) \
>  	log_error(fmt ": %s", ##__VA_ARGS__, dns_result_totext(result))
>  
> +#define log_error_position(format, ...)				\
> +	log_error("[%-15s: %4d: %-21s] " format, 			\
> +		  __FILE__, __LINE__, __func__, ##__VA_ARGS__)
> +
>  /* Basic logging functions */
>  #define log_error(format, ...)	\
>  	log_write(GET_LOG_LEVEL(ISC_LOG_ERROR), format, ##__VA_ARGS__)
> diff --git a/src/util.h b/src/util.h
> index 2b8f10e59ddacdb1d0e49cf0de3e9ab8a3786090..c61f4e7a4930717cfd7729caa2c2f36854d1903f 100644
> --- a/src/util.h
> +++ b/src/util.h
> @@ -21,6 +21,8 @@
>  #ifndef _LD_UTIL_H_
>  #define _LD_UTIL_H_
>  
> +#include "log.h"
> +
>  #define CLEANUP_WITH(result_code)				\
>  	do {							\
>  		result = (result_code);				\
> @@ -46,15 +48,17 @@
>  		(target_ptr) = isc_mem_allocate((m), (s));	\
>  		if ((target_ptr) == NULL) {			\
>  			result = ISC_R_NOMEMORY;		\
> +			log_error_position("Memory allocation failed");	\
>  			goto cleanup;				\
>  		}						\
>  	} while (0)
>  
>  #define CHECKED_MEM_GET(m, target_ptr, s)			\
>  	do {							\
>  		(target_ptr) = isc_mem_get((m), (s));		\
>  		if ((target_ptr) == NULL) {			\
>  			result = ISC_R_NOMEMORY;		\
> +			log_error_position("Memory allocation failed");	\
>  			goto cleanup;				\
>  		}						\
>  	} while (0)
> @@ -67,6 +71,7 @@
>  		(target) = isc_mem_strdup((m), (source));	\
>  		if ((target) == NULL) {				\
>  			result = ISC_R_NOMEMORY;		\
> +			log_error_position("Memory allocation failed");	\
>  			goto cleanup;				\
>  		}						\
>  	} while (0)
> -- 
> 1.7.11.7
> 


-- 
Adam Tkac, Red Hat, Inc.