Add epoch timestamps (secs.usecs) to the log messages emitted by
lhsmtool_posix. Change the single use of CT_DEBUG() to
CT_TRACE(). Remove the unused macro CT_PRINTF().
Signed-off-by: John L. Hammond <john.hammond@intel.com>
Change-Id: I227d00c97f93a09ac9322213d255102b8a3cf612
Reviewed-on: http://review.whamcloud.com/12042
Tested-by: Jenkins
Tested-by: Maloo <hpdd-maloo@intel.com>
Reviewed-by: James Nunez <james.a.nunez@intel.com>
Reviewed-by: Faccini Bruno <bruno.faccini@intel.com>
Reviewed-by: Nathaniel Clark <nathaniel.l.clark@intel.com>
Reviewed-by: Oleg Drokin <oleg.drokin@intel.com>
#include <stdlib.h>
#include <dirent.h>
#include <errno.h>
#include <stdlib.h>
#include <dirent.h>
#include <errno.h>
#include <sys/xattr.h>
#include <sys/syscall.h>
#include <sys/types.h>
#include <sys/xattr.h>
#include <sys/syscall.h>
#include <sys/types.h>
static struct hsm_copytool_private *ctdata;
static struct hsm_copytool_private *ctdata;
+static inline double ct_now(void)
+{
+ struct timeval tv;
+
+ gettimeofday(&tv, NULL);
-#define CT_ERROR(_rc, _format, ...) \
+ return tv.tv_sec + 0.000001 * tv.tv_usec;
+}
+
+#define CT_ERROR(_rc, _format, ...) \
llapi_error(LLAPI_MSG_ERROR, _rc, \
llapi_error(LLAPI_MSG_ERROR, _rc, \
- "%s[%ld]: "_format, \
- cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
-#define CT_DEBUG(_format, ...) \
+ "%f %s[%ld]: "_format, \
+ ct_now(), cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
+
+#define CT_DEBUG(_format, ...) \
llapi_error(LLAPI_MSG_DEBUG | LLAPI_MSG_NO_ERRNO, 0, \
llapi_error(LLAPI_MSG_DEBUG | LLAPI_MSG_NO_ERRNO, 0, \
- "%s[%ld]: "_format, \
- cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
+ "%f %s[%ld]: "_format, \
+ ct_now(), cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
+
#define CT_WARN(_format, ...) \
llapi_error(LLAPI_MSG_WARN | LLAPI_MSG_NO_ERRNO, 0, \
#define CT_WARN(_format, ...) \
llapi_error(LLAPI_MSG_WARN | LLAPI_MSG_NO_ERRNO, 0, \
- "%s[%ld]: "_format, \
- cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
-#define CT_TRACE(_format, ...) \
+ "%f %s[%ld]: "_format, \
+ ct_now(), cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
+
+#define CT_TRACE(_format, ...) \
llapi_error(LLAPI_MSG_INFO | LLAPI_MSG_NO_ERRNO, 0, \
llapi_error(LLAPI_MSG_INFO | LLAPI_MSG_NO_ERRNO, 0, \
- "%s[%ld]: "_format, \
- cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
-#define CT_PRINTF(_format, ...) \
- llapi_printf(LLAPI_MSG_NORMAL, \
- "%s[%ld]: "_format, \
- cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
+ "%f %s[%ld]: "_format, \
+ ct_now(), cmd_name, syscall(SYS_gettid), ## __VA_ARGS__)
static void usage(const char *name, int rc)
{
static void usage(const char *name, int rc)
{
char *buf = NULL;
__u64 write_total = 0;
__u64 length;
char *buf = NULL;
__u64 write_total = 0;
__u64 length;
+ double start_time = ct_now();
time_t last_print_time = time(NULL);
int rc = 0;
time_t last_print_time = time(NULL);
int rc = 0;
- CT_TRACE("going to copy data from '%s' to '%s'", src, dst);
-
if (fstat(src_fd, &src_st) < 0) {
rc = -errno;
CT_ERROR(rc, "cannot stat '%s'", src);
if (fstat(src_fd, &src_st) < 0) {
rc = -errno;
CT_ERROR(rc, "cannot stat '%s'", src);
- CT_DEBUG("Going to copy "LPU64" bytes %s -> %s\n", length, src, dst);
+ CT_TRACE("start copy of "LPU64" bytes from '%s' to '%s'",
+ length, src, dst);
while (write_total < length) {
ssize_t rsize;
while (write_total < length) {
ssize_t rsize;
if (buf != NULL)
free(buf);
if (buf != NULL)
free(buf);
+ CT_TRACE("copied "LPU64" bytes in %f seconds",
+ length, ct_now() - start_time);
+