From: Axel Waggershauser <awagger@web.de>

condense gp_log_data debug output.

- changed gp_log_data to take a printf style debug string
  -> new major version of libgphoto2_port
- adjusted all callers



git-svn-id: https://svn.code.sf.net/p/gphoto/code/trunk/libgphoto2@15175 67ed7778-7388-44ab-90cf-0a291f65f57c

14 files changed, 168 insertions, 181 deletions

diff --git a/camlibs/canon/canon.c b/camlibs/canon/canon.c
index 0bcf6e89a..da9444d4c 100644
--- a/camlibs/canon/canon.c
+++ b/camlibs/canon/canon.c
@@ -1686,10 +1686,9 @@ canon_int_set_file_attributes (Camera *camera, const char *file, const char *dir
                 return GP_ERROR_CORRUPTED_DATA;
         }
 
-        gp_log (GP_LOG_DATA, "canon/canon.c",
-                "canon_int_set_file_attributes: returned four bytes as expected, "
-                "we should check if they indicate error or not. Returned data :");
-        gp_log_data ("canon", (char *)msg, 4);
+        GP_LOG_DATA ((char *)msg, 4,
+                     "canon_int_set_file_attributes: returned four bytes as expected, "
+                     "we should check if they indicate error or not. Returned data:");
 
         return GP_OK;
 }
@@ -3292,11 +3291,9 @@ canon_int_list_directory (Camera *camera, const char *folder, CameraList *list,
                 }
 
                 /* 10 bytes of attributes, size and date, a name and a NULL terminating byte */
-                /* don't use GP_DEBUG since we log this with GP_LOG_DATA */
-                gp_log (GP_LOG_DATA, "canon/canon.c",
-                        "canon_int_list_directory: dirent determined to be %li=0x%lx bytes :",
-                        (long)dirent_ent_size, (long)dirent_ent_size);
-                gp_log_data ("canon", (char *)pos, dirent_ent_size);
+                GP_LOG_DATA ((char *)pos, dirent_ent_size,
+                             "canon_int_list_directory: dirent determined to be %li=0x%lx bytes :",
+                             (long)dirent_ent_size, (long)dirent_ent_size);
                 if (dirent_name_len) {
                         /* OK, this directory entry has a name in it. */
 
@@ -3858,11 +3855,9 @@ canon_int_get_info_func (Camera *camera, const char *folder,
                 }
 
                 /* 10 bytes of attributes, size and date, a name and a NULL terminating byte */
-                /* don't use GP_DEBUG since we log this with GP_LOG_DATA */
-                gp_log (GP_LOG_DATA, "canon/canon.c",
-                        "canon_int_get_info_func: dirent determined to be %li=0x%lx bytes :",
-                        (long)dirent_ent_size, (long)dirent_ent_size);
-                gp_log_data ("canon", (char *)pos, dirent_ent_size);
+                GP_LOG_DATA ((char *)pos, dirent_ent_size,
+                             "canon_int_get_info_func: dirent determined to be %li=0x%lx bytes:",
+                             (long)dirent_ent_size, (long)dirent_ent_size);
                 if (dirent_name_len) {
                         /* OK, this directory entry has a name in it. */
 
diff --git a/camlibs/canon/serial.c b/camlibs/canon/serial.c
index 2602fc857..de99a9a45 100644
--- a/camlibs/canon/serial.c
+++ b/camlibs/canon/serial.c
@@ -338,11 +338,7 @@ canon_serial_recv_frame (Camera *camera, int *len)
 		*p++ = c;
 	}
 
-	/* If you don't want to see the data dumped, change the frontend to
-	 * set a lower debug level
-	 */
-	gp_log (GP_LOG_DATA, "canon", "RECV (without CANON_FBEG and CANON_FEND bytes)");
-	gp_log_data ("canon", (char *)buffer, p - buffer);
+	GP_LOG_DATA ((char *)buffer, p - buffer, "RECV (without CANON_FBEG and CANON_FEND bytes)");
 
 	if (len)
 		*len = p - buffer;
@@ -1139,11 +1135,9 @@ canon_serial_get_dirents (Camera *camera, unsigned char **dirent_data,
 		return GP_ERROR;
 	}
 
-	/* don't use GP_DEBUG since we log this with GP_LOG_DATA */
-	gp_log (GP_LOG_DATA, "canon",
-		"canon_serial_get_dirents: "
-		"dirent packet received from canon_serial_dialogue:");
-	gp_log_data ("canon", (char *)p, *dirents_length);
+	GP_LOG_DATA ((char *)p, *dirents_length,
+				 "canon_serial_get_dirents: "
+				 "dirent packet received from canon_serial_dialogue:");
 
 	/* the first five bytes is only for the RS232 implementation
 	 * of this command, we do not need to copy them so therefore
@@ -1180,11 +1174,9 @@ canon_serial_get_dirents (Camera *camera, unsigned char **dirent_data,
 			return GP_ERROR;
 		}
 
-		/* don't use GP_DEBUG since we log this with GP_LOG_DATA */
-		gp_log (GP_LOG_DATA, "canon",
-			"canon_serial_get_dirents: "
-			"dirent packet received from canon_serial_recv_msg:");
-		gp_log_data ("canon", (char *)p, *dirents_length);
+		GP_LOG_DATA ((char *)p, *dirents_length,
+					 "canon_serial_get_dirents: "
+					 "dirent packet received from canon_serial_recv_msg:");
 
 		/* the first five bytes is only for the RS232 implementation,
 		 * don't count them when checking dirent size
diff --git a/camlibs/canon/usb.c b/camlibs/canon/usb.c
index 6c38c5497..ddc04565a 100644
--- a/camlibs/canon/usb.c
+++ b/camlibs/canon/usb.c
@@ -1431,10 +1431,8 @@ canon_usb_dialogue_full (Camera *camera, canonCommandIndex canon_funct, unsigned
                 return NULL;
         }
 
-        if (payload_length) {
-                GP_DEBUG ("Payload :");
-                gp_log_data ("canon", (char *)payload, (long)payload_length);
-        }
+        if (payload_length)
+                GP_LOG_DATA ((char *)payload, (long)payload_length, "Payload:");
 
         if ((payload_length + 0x50) > sizeof (packet)) {
                 gp_log (GP_LOG_DEBUG, "canon/usb.c",
diff --git a/camlibs/hp215/hp215.c b/camlibs/hp215/hp215.c
index 89fb322c5..6a762db21 100644
--- a/camlibs/hp215/hp215.c
+++ b/camlibs/hp215/hp215.c
@@ -371,8 +371,7 @@ hp_send_command_and_receive_blob(
 		memcpy (*msg, msgbuf+5, replydatalen-2);
 	}
 	gp_log (GP_LOG_DEBUG, "hp215", "Read Blob: retcode is %04x", *retcode);
-	gp_log (GP_LOG_DEBUG, "hp215", "Read Blob: argument block is:");
-	gp_log_data ("hp215", (char*)*msg, *msglen);
+	GP_LOG_DATA ((char*)*msg, *msglen, "Read Blob: argument block is:");
 	return GP_OK;
 }
 
diff --git a/camlibs/ptp2/library.c b/camlibs/ptp2/library.c
index 1ca979771..082a54a8f 100644
--- a/camlibs/ptp2/library.c
+++ b/camlibs/ptp2/library.c
@@ -2201,7 +2201,7 @@ camera_capture_preview (Camera *camera, CameraFile *file, GPContext *context)
 							len = size;
 							GP_LOG_E ("len=%d larger than rest size %ld", len, (size-(xdata-data)));
 						}
-						gp_log_data ("ptp2_capture_eos_preview", (char*)xdata, len);
+						GP_LOG_DATA ((char*)xdata, len, "get_viewfinder_image header:");
 						xdata = xdata+len;
 						continue;
 					case 9:
@@ -2225,13 +2225,12 @@ camera_capture_preview (Camera *camera, CameraFile *file, GPContext *context)
 							len  = dtoh32a(xdata);
 							type = dtoh32a(xdata+4);
 
-							GP_LOG_D ("get_viewfinder_image header: len=%d type=%d", len, type);
 							if (len > (size-(xdata-data))) {
 								len = size;
 								GP_LOG_E ("len=%d larger than rest size %ld", len, (size-(xdata-data)));
 								break;
 							}
-							gp_log_data ("ptp2_capture_eos_preview", (char*)xdata, len);
+							GP_LOG_DATA ((char*)xdata, len, "get_viewfinder_image header:");
 							xdata = xdata+len;
 						}
 						free (data);
diff --git a/camlibs/ptp2/olympus-wrap.c b/camlibs/ptp2/olympus-wrap.c
index 7f171b4ff..0484c1656 100644
--- a/camlibs/ptp2/olympus-wrap.c
+++ b/camlibs/ptp2/olympus-wrap.c
@@ -379,7 +379,7 @@ ums_wrap_getdata (PTPParams* params, PTPContainer* ptp, PTPDataHandler *putter)
 	GP_LOG_D ("send_scsi_cmd 2 ret  %d", ret);
 	/* skip away the 12 byte header */
 	if (recvlen >= 16)
-		gp_log_data ("ptp2/olympus/getdata", data + PTP_USB_BULK_HDR_LEN, recvlen - PTP_USB_BULK_HDR_LEN);
+		GP_LOG_DATA (data + PTP_USB_BULK_HDR_LEN, recvlen - PTP_USB_BULK_HDR_LEN, "ptp2/olympus/getdata");
 	ret = putter->putfunc ( params, putter->priv, recvlen - PTP_USB_BULK_HDR_LEN, (unsigned char*)data + PTP_USB_BULK_HDR_LEN);
 	free (data);
 	if (ret != PTP_RC_OK) {
diff --git a/camlibs/ptp2/ptpip.c b/camlibs/ptp2/ptpip.c
index 2ea2b14ba..c22860f9e 100644
--- a/camlibs/ptp2/ptpip.c
+++ b/camlibs/ptp2/ptpip.c
@@ -125,7 +125,7 @@ ptp_ptpip_sendreq (PTPParams* params, PTPContainer* req)
 	default:
 		break;
 	}
-	gp_log_data ( "ptpip/oprequest", (char*)request, len);
+	GP_LOG_DATA ( (char*)request, len, "ptpip/oprequest data:");
 	ret = write (params->cmdfd, request, len);
 	free (request);
 	if (ret == -1)
@@ -149,7 +149,7 @@ ptp_ptpip_generic_read (PTPParams *params, int fd, PTPIPHeader *hdr, unsigned ch
 			perror ("read PTPIPHeader");
 			return PTP_RC_GeneralError;
 		}
-		gp_log_data ( "ptpip/generic_read", (char*)xhdr+curread, ret);
+		GP_LOG_DATA ((char*)xhdr+curread, ret, "ptpip/generic_read data:");
 		curread += ret;
 		if (ret == 0) {
 			GP_LOG_E ("End of stream after reading %d bytes of ptpipheader", ret);
@@ -174,7 +174,7 @@ ptp_ptpip_generic_read (PTPParams *params, int fd, PTPIPHeader *hdr, unsigned ch
 			free (*data);*data = NULL;
 			return PTP_RC_GeneralError;
 		} else {
-			gp_log_data ( "ptpip/generic_read", (char*)((*data)+curread), ret);
+			GP_LOG_DATA ((char*)((*data)+curread), ret, "ptpip/generic_read data:");
 		}
 		if (ret == 0)
 			break;
@@ -234,7 +234,7 @@ ptp_ptpip_senddata (PTPParams* params, PTPContainer* ptp,
 	htod32a(&request[ptpip_startdata_transid  + 8],ptp->Transaction_ID);
 	htod32a(&request[ptpip_startdata_totallen + 8],size);
 	htod32a(&request[ptpip_startdata_unknown  + 8],0);
-	gp_log_data ( "ptpip/senddata", (char*)request, sizeof(request));
+	GP_LOG_DATA ((char*)request, sizeof(request), "ptpip/senddata header:");
 	ret = write (params->cmdfd, request, sizeof(request));
 	if (ret == -1)
 		perror ("sendreq/write to cmdfd");
@@ -267,7 +267,7 @@ ptp_ptpip_senddata (PTPParams* params, PTPContainer* ptp,
 		htod32a(&xdata[ptpip_type], type);
 		htod32a(&xdata[ptpip_len], towrite2);
 		htod32a(&xdata[ptpip_data_transid+8], ptp->Transaction_ID);
-		gp_log_data("ptpip/senddata", (char*)xdata, towrite2);
+		GP_LOG_DATA ((char*)xdata, towrite2, "ptpip/senddata data:");
 		written = 0;
 		while (written < towrite2) {
 			ret = write (params->cmdfd, xdata+written, towrite2-written);
@@ -424,7 +424,7 @@ ptp_ptpip_init_command_request (PTPParams* params)
 	htod16a(&cmdrequest[ptpip_initcmd_name+(strlen(hostname)+1)*2],PTPIP_VERSION_MINOR);
 	htod16a(&cmdrequest[ptpip_initcmd_name+(strlen(hostname)+1)*2+2],PTPIP_VERSION_MAJOR);
 
-	gp_log_data ( "ptpip/init_cmd", (char*)cmdrequest, len);
+	GP_LOG_DATA ((char*)cmdrequest, len, "ptpip/init_cmd data:");
 	ret = write (params->cmdfd, cmdrequest, len);
 	free (cmdrequest);
 	if (ret == -1) {
@@ -485,7 +485,7 @@ ptp_ptpip_init_event_request (PTPParams* params)
 	htod32a(&evtrequest[ptpip_len],ptpip_eventinit_size);
 	htod32a(&evtrequest[ptpip_eventinit_idx],params->eventpipeid);
 
-	gp_log_data ( "ptpip/init_event", (char*)evtrequest, ptpip_eventinit_size);
+	GP_LOG_DATA ((char*)evtrequest, ptpip_eventinit_size, "ptpip/init_event data:");
 	ret = write (params->evtfd, evtrequest, ptpip_eventinit_size);
 	if (ret == -1) {
 		perror("write init evt request");
diff --git a/coverity-model.c b/coverity-model.c
index 6c534ea9f..7dd169640 100644
--- a/coverity-model.c
+++ b/coverity-model.c
@@ -55,7 +55,7 @@ int gp_port_send_scsi_cmd (GPPort *port, int to_dev,
 	}
 }
 
-void gp_log_data (const char *domain, const char *data, unsigned int size) {
+void gp_log_data (const char *domain, const char *data, unsigned int size, const char* format, ...) {
 	/* considered a tainted sink ... but is not one. */
 }
 
diff --git a/libgphoto2_port/configure.ac b/libgphoto2_port/configure.ac
index 7de1e3eee..cf125a1c2 100644
--- a/libgphoto2_port/configure.ac
+++ b/libgphoto2_port/configure.ac
@@ -47,9 +47,9 @@ dnl A:R:C=7:0:7 libgphoto2_port-0.7.0 libgphoto2-2.3
 dnl A:R:C=7:1:7 libgphoto2_port-0.7.1 libgphoto2-2.3.x
 dnl A:R:C=8:0:8 libgphoto2_port-0.8.0 libgphoto2-2.4.x
 dnl A:R:C=9:1:9 libgphoto2_port-0.10.0 libgphoto2-2.5.x
-AC_SUBST([LIBGPHOTO2_PORT_AGE],      [1])
-AC_SUBST([LIBGPHOTO2_PORT_REVISION], [1])
-AC_SUBST([LIBGPHOTO2_PORT_CURRENT],  [11])
+AC_SUBST([LIBGPHOTO2_PORT_AGE],      [0])
+AC_SUBST([LIBGPHOTO2_PORT_REVISION], [0])
+AC_SUBST([LIBGPHOTO2_PORT_CURRENT],  [12])
 AC_SUBST([LIBGPHOTO2_PORT_CURRENT_MIN],
          [`expr $LIBGPHOTO2_PORT_CURRENT - $LIBGPHOTO2_PORT_AGE`])
 AC_SUBST([LIBGPHOTO2_PORT_VERSION_INFO],
diff --git a/libgphoto2_port/gphoto2/gphoto2-port-log.h b/libgphoto2_port/gphoto2/gphoto2-port-log.h
index 80bf9b7f9..521091d8c 100644
--- a/libgphoto2_port/gphoto2/gphoto2-port-log.h
+++ b/libgphoto2_port/gphoto2/gphoto2-port-log.h
@@ -85,7 +85,12 @@ void gp_logv     (GPLogLevel level, const char *domain, const char *format,
 	__attribute__((__format__(printf,3,0)))
 #endif
 ;
-void gp_log_data (const char *domain, const char *data, unsigned int size);
+void gp_log_data (const char *domain, const char *data, unsigned int size,
+		  const char *format, ...)
+#ifdef __GNUC__
+__attribute__((__format__(printf,4,5)))
+#endif
+;
 
 /*
  * GP_DEBUG:
@@ -110,7 +115,7 @@ void gp_log_data (const char *domain, const char *data, unsigned int size);
  */
 #define GP_LOG_D(...) gp_log(GP_LOG_DEBUG, __func__, __VA_ARGS__)
 #define GP_LOG_E(...) gp_log_with_source_location(GP_LOG_ERROR, __FILE__, __LINE__, __func__, __VA_ARGS__)
-#define GP_LOG_DATA(DATA, SIZE) gp_log_data(__func__, DATA, SIZE)
+#define GP_LOG_DATA(DATA, SIZE, MSG, ...) gp_log_data(__func__, DATA, SIZE, MSG, ##__VA_ARGS__)
 
 #elif defined(__GNUC__) &&  __GNUC__ >= 2
 #define GP_DEBUG(msg, params...) \
@@ -122,7 +127,7 @@ void gp_log_data (const char *domain, const char *data, unsigned int size);
  */
 #define GP_LOG_D(...) gp_log(GP_LOG_DEBUG, __func__, __VA_ARGS__)
 #define GP_LOG_E(...) gp_log_with_source_location(GP_LOG_ERROR, __FILE__, __LINE__, __func__, __VA_ARGS__)
-#define GP_LOG_DATA(DATA, SIZE) gp_log_data(__func__, DATA, SIZE)
+#define GP_LOG_DATA(DATA, SIZE, MSG, ...) gp_log_data(__func__, DATA, SIZE, MSG, ##__VA_ARGS__)
 
 #else
 # ifdef __GNUC__
@@ -131,7 +136,7 @@ void gp_log_data (const char *domain, const char *data, unsigned int size);
 #define GP_DEBUG (void) 
 #define GP_LOG_D(...) /* no-op */
 #define GP_LOG_E(...) /* no-op */
-#define GP_LOG_DATA(DATA, SIZE) /* no-op */
+#define GP_LOG_DATA(DATA, SIZE, ...) /* no-op */
 #endif
 #endif /* _GPHOTO2_INTERNAL_CODE */
 
@@ -150,18 +155,18 @@ void gp_log_data (const char *domain, const char *data, unsigned int size);
 #define GP_DEBUG(...) /* no-op */
 #define GP_LOG_D(...) /* no-op */
 #define GP_LOG_E(...) /* no-op */
-#define GP_LOG_DATA(DATA, SIZE) /* no-op */
+#define GP_LOG_DATA(DATA, SIZE, ...) /* no-op */
 
 #elif defined(__GNUC__)
 #define GP_DEBUG(msg, params...) /* no-op */
 #define GP_LOG_D(...) /* no-op */
 #define GP_LOG_E(...) /* no-op */
-#define GP_LOG_DATA(DATA, SIZE) /* no-op */
+#define GP_LOG_DATA(DATA, SIZE, ...) /* no-op */
 #else
 #define GP_DEBUG (void)
 #define GP_LOG_D (void /* no-op */
 #define GP_LOG_E (void) /* no-op */
-#define GP_LOG_DATA(DATA, SIZE) /* no-op */
+#define GP_LOG_DATA(void) /* no-op */
 #endif
 #endif /* _GPHOTO2_INTERNAL_CODE */
 
@@ -202,7 +207,7 @@ void gp_log_data (const char *domain, const char *data, unsigned int size);
   unsigned int 
   gpi_string_list_to_flags(const char *str[], 
 			   const StringFlagItem *map);
-  
+
 #define C_MEM(MEM) do {\
 	if ((MEM) == NULL) {\
 		GP_LOG_E ("Out of memory: '%s' failed.", #MEM);\
diff --git a/libgphoto2_port/libgphoto2_port/gphoto2-port-log.c b/libgphoto2_port/libgphoto2_port/gphoto2-port-log.c
index 84d4b788f..8efaff25f 100644
--- a/libgphoto2_port/libgphoto2_port/gphoto2-port-log.c
+++ b/libgphoto2_port/libgphoto2_port/gphoto2-port-log.c
@@ -95,6 +95,36 @@ gp_log_add_func (GPLogLevel level, GPLogFunc func, void *data)
 	return (log_funcs_count);
 }
 
+
+static char*
+gpi_vsnprintf (const char* format, va_list args)
+{
+	va_list xargs;
+	int strsize;
+	char *str;
+
+#ifdef HAVE_VA_COPY
+	va_copy (xargs, args);
+#else
+	/* according to 'the web', the only interesting compiler without va_copy is MSVC
+	 * and there a simple assignment is the way to go */
+	xargs = args;
+#endif
+
+	/* query the size necessary for the string, add the terminating '\0' */
+	strsize = vsnprintf (NULL, 0, format, xargs) + 1;
+	va_end (xargs);
+
+	str = malloc(strsize);
+	if (!str)
+		return NULL;
+
+	/* actually print the string into the buffer */
+	vsnprintf (str, strsize, format, args);
+
+	return str;
+}
+
 /**
  * \brief Remove a logging receiving function
  * \param id an id (return value of #gp_log_add_func)
@@ -167,35 +197,43 @@ gp_log_remove_func (int id)
  **/
 /* coverity[-tainted_sink] */
 void
-gp_log_data (const char *domain, const char *data, unsigned int size)
+gp_log_data (const char *domain, const char *data, unsigned int size, const char *format, ...)
 {
+	va_list args;
 	static const char hexchars[16] = "0123456789abcdef";
-	char *curline, *result;
+	char *curline, *result = 0, *msg = 0;
 	int x = HEXDUMP_INIT_X;
 	int y = HEXDUMP_INIT_Y;
-	unsigned int index;
+	unsigned int index, original_size = size;
 	unsigned char value;
 
+	va_start (args, format);
+	msg = gpi_vsnprintf(format, args);
+	va_end (args);
+	if (!msg) {
+		GP_LOG_E ("Malloc for expanding format string '%s' failed.", format);
+		goto exit;
+	}
+
 	if (!data) {
-		gp_log (GP_LOG_DATA, domain, "No hexdump (NULL buffer)");
-		return;
+		gp_log (GP_LOG_DATA, domain, "%s (no hexdump, NULL buffer)", msg);
+		goto exit;
 	}
 
 	if (!size) {
-		gp_log (GP_LOG_DATA, domain, "Empty hexdump of empty buffer");
-		return;
+		gp_log (GP_LOG_DATA, domain, "%s (empty hexdump of empty buffer)", msg);
+		goto exit;
 	}
 
 	if (size > 1024*1024) {
 		/* Does not make sense for 200 MB movies */
-		gp_log (GP_LOG_DATA, domain, "Truncating dump from %d bytes to 1MB", size);
 		size = 1024*1024;
 	}
 
 	curline = result = malloc ((HEXDUMP_LINE_WIDTH+1)*(((size-1)/16)+1)+1);
 	if (!result) {
 		GP_LOG_E ("Malloc for %i bytes failed", (HEXDUMP_LINE_WIDTH+1)*(((size-1)/16)+1)+1);
-		return;
+		goto exit;
 	}
 
 	for (index = 0; index < size; ++index) {
@@ -224,8 +262,13 @@ gp_log_data (const char *domain, const char *data, unsigned int size)
         }
         curline[0] = '\0';
 
-	gp_log (GP_LOG_DATA, domain, "Hexdump of %i = 0x%x bytes follows:\n%s",
-		size, size, result);
+        if (size == original_size)
+                gp_log (GP_LOG_DATA, domain, "%s (hexdump of %d bytes)\n%s", msg, size, result);
+        else
+                gp_log (GP_LOG_DATA, domain, "%s (hexdump of the first %d of %d bytes)\n%s", msg, size, original_size, result);
+
+exit:
+	free (msg);
 	free (result);
 }
 
@@ -252,44 +295,17 @@ gp_logv (GPLogLevel level, const char *domain, const char *format,
 	 va_list args)
 {
 	unsigned int i;
-#ifdef HAVE_VA_COPY
-	va_list xargs;
-#else
-#define xargs args
-#endif
-	int strsize = 1000;
-	char *str;
-	int n;
+	char *str = 0;
 
 	if (!log_funcs_count)
 		return;
 
-	str = malloc(strsize);
-	if (!str) return;
-#ifdef HAVE_VA_COPY
-	va_copy (xargs, args);
-#endif
-	n = vsnprintf (str, strsize, format, xargs);
-#ifdef HAVE_VA_COPY
-	va_end(xargs);
-#endif
-	if (n+1>strsize) {
-		free (str);
-		str = malloc(n+1);
-		if (!str) {
-			va_end(args);
-			return;
-		}
-		strsize = n+1;
-#ifdef HAVE_VA_COPY
-		va_copy (xargs, args);
-#endif
-		n = vsnprintf (str, strsize, format, xargs);
-#ifdef HAVE_VA_COPY
-		va_end(xargs);
-#endif
+	str = gpi_vsnprintf(format, args);
+	if (!str) {
+		GP_LOG_E ("Malloc for expanding format string '%s' failed.", format);
+		return;
 	}
-	va_end(args);
+
 	for (i = 0; i < log_funcs_count; i++)
 		if (log_funcs[i].level >= level)
 			log_funcs[i].func (level, domain, str, log_funcs[i].data);
@@ -371,7 +387,7 @@ gp_log_remove_func (int id)
 }
 
 void
-gp_log_data (const char *domain, const char *data, unsigned int size)
+gp_log_data (const char *domain, const char *data, unsigned int size, const char *format, ...)
 {
 }
 
diff --git a/libgphoto2_port/libgphoto2_port/gphoto2-port.c b/libgphoto2_port/libgphoto2_port/gphoto2-port.c
index 42673ca4c..1842970b9 100644
--- a/libgphoto2_port/libgphoto2_port/gphoto2-port.c
+++ b/libgphoto2_port/libgphoto2_port/gphoto2-port.c
@@ -59,6 +59,13 @@
 #define CHECK_SUPP(p,t,o) {if (!(o)) {gp_port_set_error ((p), _("The operation '%s' is not supported by this device"), (t)); return (GP_ERROR_NOT_SUPPORTED);}}
 #define CHECK_INIT(p) {if (!(p)->pc->ops) {gp_port_set_error ((p), _("The port has not yet been initialized")); return (GP_ERROR_BAD_PARAMETERS);}}
 
+#define LOG_DATA(DATA, SIZE, EXPECTED, MSG_PRE, MSG_POST, ...) \
+	if (SIZE != EXPECTED) \
+		GP_LOG_DATA (DATA, SIZE, MSG_PRE " %i = 0x%x out of %i bytes " MSG_POST, SIZE, SIZE, EXPECTED, ##__VA_ARGS__); \
+	else \
+		GP_LOG_DATA (DATA, SIZE, MSG_PRE " %i = 0x%x bytes " MSG_POST, SIZE, SIZE, ##__VA_ARGS__)
+
+
 /**
  * \brief Internal private libgphoto2_port data.
  * This structure contains private data.
@@ -382,19 +389,20 @@ gp_port_write (GPPort *port, const char *data, int size)
 {
 	int retval;
 
-	GP_LOG_D ("Writing %i=0x%x byte(s) to port...", size, size);
+        gp_log (GP_LOG_DATA, __func__, "Writing %i = 0x%x bytes to port...", size, size);
 
-	C_PARAMS (port && data);
+ 	C_PARAMS (port && data);
 	CHECK_INIT (port);
 
-	GP_LOG_DATA (data, size);
-
 	/* Check if we wrote all bytes */
 	CHECK_SUPP (port, "write", port->pc->ops->write);
 	retval = port->pc->ops->write (port, data, size);
-	CHECK_RESULT (retval);
-	if ((port->type != GP_PORT_SERIAL) && (retval != size))
-		GP_LOG_D ("Could only write %i out of %i bytes.", retval, size);
+	if (retval < 0) {
+		GP_LOG_E ("Writing %i = 0x%x bytes to port failed: %s (%d)",
+			  size, size, gp_port_result_as_string(retval), retval);
+		return retval;
+	}
+	LOG_DATA (data, retval, size, "Wrote  ", "to port:");
 
 	return (retval);
 }
@@ -416,7 +424,7 @@ gp_port_read (GPPort *port, char *data, int size)
 {
         int retval;
 
-	GP_LOG_D ("Reading %i=0x%x bytes from port...", size, size);
+	gp_log (GP_LOG_DATA, __func__, "Reading %i = 0x%x bytes from port...", size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -424,11 +432,12 @@ gp_port_read (GPPort *port, char *data, int size)
 	/* Check if we read as many bytes as expected */
 	CHECK_SUPP (port, "read", port->pc->ops->read);
 	retval = port->pc->ops->read (port, data, size);
-	CHECK_RESULT (retval);
-	if (retval != size)
-		GP_LOG_D ("Could only read %i out of %i bytes.", retval, size);
-
-	GP_LOG_DATA (data, retval);
+	if (retval < 0) {
+		GP_LOG_E ("Reading %i = 0x%x bytes from port failed: %s (%d)",
+			  size, size, gp_port_result_as_string(retval), retval);
+		return retval;
+	}
+	LOG_DATA (data, retval, size, "Read   ", "from port:");
 
 	return (retval);
 }
@@ -451,7 +460,7 @@ gp_port_check_int (GPPort *port, char *data, int size)
 {
         int retval;
 
-	GP_LOG_D ("Reading %i=0x%x bytes from interrupt endpoint...", size, size);
+	gp_log (GP_LOG_DATA, __func__, "Reading %i = 0x%x bytes from interrupt endpoint...", size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -460,10 +469,7 @@ gp_port_check_int (GPPort *port, char *data, int size)
 	CHECK_SUPP (port, "check_int", port->pc->ops->check_int);
 	retval = port->pc->ops->check_int (port, data, size, port->timeout);
 	CHECK_RESULT (retval);
-	if (retval != size)
-		GP_LOG_D ("Could only read %i out of %i bytes.", retval, size);
-
-	GP_LOG_DATA (data, retval);
+	LOG_DATA (data, retval, size, "Read   ", "from interrupt endpoint:");
 
 	return (retval);
 }
@@ -487,6 +493,8 @@ gp_port_check_int_fast (GPPort *port, char *data, int size)
 {
         int retval;
 
+        gp_log (GP_LOG_DATA, __func__, "Reading %i = 0x%x bytes from interrupt endpoint...", size, size);
+
 	C_PARAMS (port);
 	CHECK_INIT (port);
 
@@ -496,23 +504,12 @@ gp_port_check_int_fast (GPPort *port, char *data, int size)
 	CHECK_RESULT (retval);
 
 #ifdef IGNORE_EMPTY_INTR_READS
-	if (retval != size && retval != 0 )
-#else
-	if (retval != size )
-#endif
-		GP_LOG_D ("Could only read %i out of %i bytes.", retval, size);
-
-#ifdef IGNORE_EMPTY_INTR_READS
-	if ( retval != 0 ) {
-#endif
-		/* For Canon cameras, we will make lots of
-		   reads that will return zero length. Don't
-		   bother to log them as errors. */
-		GP_LOG_D ("Reading %i=0x%x bytes from interrupt endpoint (fast)...", size, size);
-		GP_LOG_DATA (data, retval);
-#ifdef IGNORE_EMPTY_INTR_READS
-	}
+	/* For Canon cameras, we will make lots of
+	   reads that will return zero length. Don't
+	   bother to log them as errors. */
+	if (retval != 0 )
 #endif
+		LOG_DATA (data, retval, size, "Read   ", "from interrupt endpoint (fast):");
 
 	return (retval);
 }
@@ -865,9 +862,8 @@ gp_port_usb_msg_write (GPPort *port, int request, int value, int index,
 {
         int retval;
 
-	GP_LOG_D ("Writing message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
-		  request, value, index, size, size);
-	GP_LOG_DATA (bytes, size);
+	GP_LOG_DATA (bytes, size, "Writing message (request=0x%x value=0x%x index=0x%x size=%i=0x%x):",
+		     request, value, index, size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -899,8 +895,8 @@ gp_port_usb_msg_read (GPPort *port, int request, int value, int index,
 {
         int retval;
 
-	GP_LOG_D ("Reading message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
-		  request, value, index, size, size);
+	gp_log (GP_LOG_DATA, __func__, "Reading message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
+		request, value, index, size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -909,10 +905,9 @@ gp_port_usb_msg_read (GPPort *port, int request, int value, int index,
         retval = port->pc->ops->msg_read (port, request, value, index, bytes, size);
 	CHECK_RESULT (retval);
 
-	if (retval != size)
-		GP_LOG_D ("Could only read %i out of %i bytes.", retval, size);
+	LOG_DATA (bytes, retval, size, "Read", "USB message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)",
+		  request, value, index, size, size);
 
-	GP_LOG_DATA (bytes, retval);
         return (retval);
 }
 
@@ -940,9 +935,8 @@ gp_port_usb_msg_interface_write (GPPort *port, int request,
 {
         int retval;
 
-	GP_LOG_D ("Writing message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
-		  request, value, index, size, size);
-	GP_LOG_DATA (bytes, size);
+	GP_LOG_DATA (bytes, size, "Writing message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
+		     request, value, index, size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -976,8 +970,8 @@ gp_port_usb_msg_interface_read (GPPort *port, int request, int value, int index,
 {
         int retval;
 
-	GP_LOG_D ("Reading message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
-		  request, value, index, size, size);
+	gp_log (GP_LOG_DATA, __func__, "Reading message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
+		request, value, index, size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -987,10 +981,8 @@ gp_port_usb_msg_interface_read (GPPort *port, int request, int value, int index,
         		value, index, bytes, size);
 	CHECK_RESULT (retval);
 
-	if (retval != size)
-		GP_LOG_D ("Could only read %i out of %i bytes.", retval, size);
-
-	GP_LOG_DATA (bytes, retval);
+	LOG_DATA (bytes, retval, size, "Read", "USB message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)",
+		  request, value, index, size, size);
 
         return (retval);
 }
@@ -1021,9 +1013,8 @@ gp_port_usb_msg_class_write (GPPort *port, int request,
 {
         int retval;
 
-	GP_LOG_D ("Writing message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
-		  request, value, index, size, size);
-	GP_LOG_DATA (bytes, size);
+	GP_LOG_DATA (bytes, size, "Writing message (request=0x%x value=0x%x index=0x%x size=%i=0x%x):",
+		     request, value, index, size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -1057,8 +1048,8 @@ gp_port_usb_msg_class_read (GPPort *port, int request, int value, int index,
 {
         int retval;
 
-	GP_LOG_D ("Reading message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
-		  request, value, index, size, size);
+	gp_log (GP_LOG_DATA, __func__, "Reading message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)...",
+		request, value, index, size, size);
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -1068,10 +1059,8 @@ gp_port_usb_msg_class_read (GPPort *port, int request, int value, int index,
         		value, index, bytes, size);
 	CHECK_RESULT (retval);
 
-	if (retval != size)
-		GP_LOG_D ("Could only read %i out of %i bytes.", retval, size);
-
-	GP_LOG_DATA (bytes, retval);
+	LOG_DATA (bytes, retval, size, "Read", "USB message (request=0x%x value=0x%x index=0x%x size=%i=0x%x)",
+		  request, value, index, size, size);
 
         return (retval);
 }
@@ -1129,12 +1118,9 @@ int gp_port_send_scsi_cmd (GPPort *port, int to_dev,
 {
 	int retval;
 
-	GP_LOG_D ("Sending scsi cmd:");
-	GP_LOG_DATA (cmd, cmd_size);
-	if (to_dev && data_size) {
-		GP_LOG_D ("with scsi cmd data:");
-		GP_LOG_DATA (data, data_size);
-	}
+	GP_LOG_DATA (cmd, cmd_size, "Sending scsi cmd:");
+	if (to_dev && data_size)
+		GP_LOG_DATA (data, data_size, "with scsi cmd data:");
 
 	C_PARAMS (port);
 	CHECK_INIT (port);
@@ -1147,8 +1133,7 @@ int gp_port_send_scsi_cmd (GPPort *port, int to_dev,
 	GP_LOG_D ("scsi cmd result: %d", retval);
 
 	if (sense[0] != 0) {
-		GP_LOG_D ("sense data:");
-		GP_LOG_DATA (sense, sense_size);
+		GP_LOG_DATA (sense, sense_size, "sense data:");
 		/* https://secure.wikimedia.org/wikipedia/en/wiki/Key_Code_Qualifier */
 		GP_LOG_D ("sense decided:");
 		if ((sense[0]&0x7f)!=0x70) {
@@ -1171,10 +1156,8 @@ int gp_port_send_scsi_cmd (GPPort *port, int to_dev,
 		}
 	}
 
-	if (!to_dev && data_size) {
-		GP_LOG_D ("scsi cmd data:");
-		GP_LOG_DATA (data, data_size);
-	}
+	if (!to_dev && data_size)
+		GP_LOG_DATA (data, data_size, "scsi cmd data:");
 
 	return retval;
 }
diff --git a/libgphoto2_port/libusb1/libusb1.c b/libgphoto2_port/libusb1/libusb1.c
index 36a68dced..aa00730ea 100644
--- a/libgphoto2_port/libusb1/libusb1.c
+++ b/libgphoto2_port/libusb1/libusb1.c
@@ -1026,7 +1026,7 @@ gp_port_usb_match_mtp_device(struct libusb_device *dev,int *configno, int *inter
 	}
 	/* get string descriptor at 0xEE */
 	ret = usb_get_descriptor (devh, 0x03, 0xee, buf, sizeof(buf));
-	if (ret > 0) gp_log_data("get_MS_OSD",buf, ret);
+	if (ret > 0) GP_LOG_DATA (buf, ret, "get_MS_OSD");
 	if (ret < 10) goto errout;
 	if (!((buf[2] == 'M') && (buf[4]=='S') && (buf[6]=='F') && (buf[8]=='T')))
 		goto errout;
@@ -1040,7 +1040,7 @@ gp_port_usb_match_mtp_device(struct libusb_device *dev,int *configno, int *inter
 		GP_LOG_E ("ret is %d, buf[0] is %x\n", ret, buf[0]);
 		goto errout;
 	}
-	if (ret > 0) gp_log_data("get_MS_ExtDesc",buf, ret);
+	if (ret > 0) GP_LOG_DATA (buf, ret, "get_MS_ExtDesc");
 	if ((buf[0x12] != 'M') || (buf[0x13] != 'T') || (buf[0x14] != 'P')) {
 		GP_LOG_E ("buf at 0x12 is %02x%02x%02x\n", buf[0x12], buf[0x13], buf[0x14]);
 		goto errout;
@@ -1051,7 +1051,7 @@ gp_port_usb_match_mtp_device(struct libusb_device *dev,int *configno, int *inter
 		GP_LOG_E ("ret is %d, buf[0] is %x\n", ret, buf[0]);
 		goto errout;
 	}
-	if (ret > 0) gp_log_data("get_MS_ExtProp",buf, ret);
+	if (ret > 0) GP_LOG_DATA (buf, ret, "get_MS_ExtProp");
 	if ((buf[0x12] != 'M') || (buf[0x13] != 'T') || (buf[0x14] != 'P')) {
 		GP_LOG_E ("buf at 0x12 is %02x%02x%02x\n", buf[0x12], buf[0x13], buf[0x14]);
 		goto errout;
diff --git a/libgphoto2_port/usb/libusb.c b/libgphoto2_port/usb/libusb.c
index c4569a3bf..3c9002544 100644
--- a/libgphoto2_port/usb/libusb.c
+++ b/libgphoto2_port/usb/libusb.c
@@ -998,7 +998,7 @@ gp_port_usb_match_mtp_device(struct usb_device *dev,int *configno, int *interfac
 	}
 	/* get string descriptor at 0xEE */
 	ret = usb_get_descriptor (devh, 0x03, 0xee, buf, sizeof(buf));
-	if (ret > 0) gp_log_data("get_MS_OSD",buf, ret);
+	if (ret > 0) GP_LOG_DATA (buf, ret, "get_MS_OSD");
 	if (ret < 10) goto errout;
 	if (!((buf[2] == 'M') && (buf[4]=='S') && (buf[6]=='F') && (buf[8]=='T')))
 		goto errout;
@@ -1012,7 +1012,7 @@ gp_port_usb_match_mtp_device(struct usb_device *dev,int *configno, int *interfac
 		GP_LOG_E ("ret is %d, buf[0] is %x\n", ret, buf[0]);
 		goto errout;
 	}
-	if (ret > 0) gp_log_data("get_MS_ExtDesc",buf, ret);
+	if (ret > 0) GP_LOG_DATA (buf, ret, "get_MS_ExtDesc");
 	if ((buf[0x12] != 'M') || (buf[0x13] != 'T') || (buf[0x14] != 'P')) {
 		GP_LOG_E ("buf at 0x12 is %02x%02x%02x\n", buf[0x12], buf[0x13], buf[0x14]);
 		goto errout;
@@ -1023,7 +1023,7 @@ gp_port_usb_match_mtp_device(struct usb_device *dev,int *configno, int *interfac
 		GP_LOG_E ("ret is %d, buf[0] is %x\n", ret, buf[0]);
 		goto errout;
 	}
-	if (ret > 0) gp_log_data("get_MS_ExtProp",buf, ret);
+	if (ret > 0) GP_LOG_DATA (buf, ret, "get_MS_ExtProp");
 	if ((buf[0x12] != 'M') || (buf[0x13] != 'T') || (buf[0x14] != 'P')) {
 		GP_LOG_E ("buf at 0x12 is %02x%02x%02x\n", buf[0x12], buf[0x13], buf[0x14]);
 		goto errout;