* [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough
@ 2019-08-09 8:25 Eryu Guan
2019-08-09 8:25 ` [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra Eryu Guan
2019-08-09 9:34 ` [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough piaojun
0 siblings, 2 replies; 12+ messages in thread
From: Eryu Guan @ 2019-08-09 8:25 UTC (permalink / raw)
To: virtio-fs
Introduce "-o log_level=" command line option to specify current log
level (priority), valid values are "debug info warn err", e.g.
./virtiofsd -o log_level=debug ...
So only log priority higher than "debug" will be printed to
stderr/syslog. And the default level is info.
The "-o debug"/"-d" options are kept, and imply debug log level.
Signed-off-by: Eryu Guan <eguan@linux.alibaba.com>
---
contrib/virtiofsd/fuse_log.c | 9 ++-
contrib/virtiofsd/fuse_log.h | 4 +
contrib/virtiofsd/fuse_lowlevel.c | 77 +++++++-----------
contrib/virtiofsd/fuse_lowlevel.h | 1 +
contrib/virtiofsd/fuse_virtio.c | 104 ++++++++++---------------
contrib/virtiofsd/helper.c | 10 ++-
contrib/virtiofsd/passthrough_ll.c | 156 +++++++++++++++----------------------
7 files changed, 153 insertions(+), 208 deletions(-)
diff --git a/contrib/virtiofsd/fuse_log.c b/contrib/virtiofsd/fuse_log.c
index 4eb25328721e..d54b64099a2b 100644
--- a/contrib/virtiofsd/fuse_log.c
+++ b/contrib/virtiofsd/fuse_log.c
@@ -9,10 +9,10 @@
#include <stdbool.h>
#include <stdio.h>
#include <stdarg.h>
-#include <syslog.h>
#include "fuse_log.h"
static bool use_syslog;
+int current_log_level = LOG_INFO;
void fuse_log_enable_syslog(void)
{
@@ -24,10 +24,13 @@ void fuse_log_enable_syslog(void)
openlog("virtiofsd", LOG_PID, LOG_DAEMON);
}
-static void fuse_vlog(int priority, const char *fmt, va_list ap)
+static void fuse_vlog(int target_level, const char *fmt, va_list ap)
{
+ if (current_log_level < target_level)
+ return;
+
if (use_syslog) {
- vsyslog(priority, fmt, ap);
+ vsyslog(target_level, fmt, ap);
} else {
vfprintf(stderr, fmt, ap);
}
diff --git a/contrib/virtiofsd/fuse_log.h b/contrib/virtiofsd/fuse_log.h
index 3c22928d2b1d..c4dfc921b6d8 100644
--- a/contrib/virtiofsd/fuse_log.h
+++ b/contrib/virtiofsd/fuse_log.h
@@ -9,8 +9,12 @@
#ifndef FUSE_LOG_H
#define FUSE_LOG_H
+#include <syslog.h>
#include "qemu/compiler.h"
+/* Current log level */
+extern int current_log_level;
+
void fuse_log_enable_syslog(void);
void fuse_err(const char *fmt, ...) GCC_FMT_ATTR(1, 2);
void fuse_warning(const char *fmt, ...) GCC_FMT_ATTR(1, 2);
diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c
index 8d3f141d23cf..7eec2680b6de 100644
--- a/contrib/virtiofsd/fuse_lowlevel.c
+++ b/contrib/virtiofsd/fuse_lowlevel.c
@@ -155,19 +155,17 @@ static int fuse_send_msg(struct fuse_session *se, struct fuse_chan *ch,
struct fuse_out_header *out = iov[0].iov_base;
out->len = iov_length(iov, count);
- if (se->debug) {
- if (out->unique == 0) {
- fuse_debug("NOTIFY: code=%d length=%u\n",
- out->error, out->len);
- } else if (out->error) {
- fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n",
- (unsigned long long) out->unique,
- out->error, strerror(-out->error),
- out->len);
- } else {
- fuse_debug(" unique: %llu, success, outsize: %i\n",
- (unsigned long long) out->unique, out->len);
- }
+ if (out->unique == 0) {
+ fuse_debug("NOTIFY: code=%d length=%u\n",
+ out->error, out->len);
+ } else if (out->error) {
+ fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n",
+ (unsigned long long) out->unique,
+ out->error, strerror(-out->error),
+ out->len);
+ } else {
+ fuse_debug(" unique: %llu, success, outsize: %i\n",
+ (unsigned long long) out->unique, out->len);
}
if (fuse_lowlevel_is_virtio(se)) {
@@ -1668,9 +1666,7 @@ static void do_interrupt(fuse_req_t req, fuse_ino_t nodeid,
return;
}
- if (se->debug)
- fuse_debug("INTERRUPT: %llu\n",
- (unsigned long long) arg->unique);
+ fuse_debug("INTERRUPT: %llu\n", (unsigned long long) arg->unique);
req->u.i.unique = arg->unique;
@@ -1952,13 +1948,10 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid,
}
}
- if (se->debug) {
- fuse_debug("INIT: %u.%u\n", arg->major, arg->minor);
- if (arg->major == 7 && arg->minor >= 6) {
- fuse_debug("flags=0x%08x\n", arg->flags);
- fuse_debug("max_readahead=0x%08x\n",
- arg->max_readahead);
- }
+ fuse_debug("INIT: %u.%u\n", arg->major, arg->minor);
+ if (arg->major == 7 && arg->minor >= 6) {
+ fuse_debug("flags=0x%08x\n", arg->flags);
+ fuse_debug("max_readahead=0x%08x\n", arg->max_readahead);
}
se->conn.proto_major = arg->major;
se->conn.proto_minor = arg->minor;
@@ -2135,21 +2128,14 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid,
outarg.map_alignment = sysconf(_SC_PAGE_SIZE);
}
- if (se->debug) {
- fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor);
- fuse_debug(" flags=0x%08x\n", outarg.flags);
- fuse_debug(" max_readahead=0x%08x\n",
- outarg.max_readahead);
- fuse_debug(" max_write=0x%08x\n", outarg.max_write);
- fuse_debug(" max_background=%i\n",
- outarg.max_background);
- fuse_debug(" congestion_threshold=%i\n",
- outarg.congestion_threshold);
- fuse_debug(" time_gran=%u\n",
- outarg.time_gran);
- fuse_debug(" map_alignment=%u\n",
- outarg.map_alignment);
- }
+ fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor);
+ fuse_debug(" flags=0x%08x\n", outarg.flags);
+ fuse_debug(" max_readahead=0x%08x\n", outarg.max_readahead);
+ fuse_debug(" max_write=0x%08x\n", outarg.max_write);
+ fuse_debug(" max_background=%i\n", outarg.max_background);
+ fuse_debug(" congestion_threshold=%i\n", outarg.congestion_threshold);
+ fuse_debug(" time_gran=%u\n", outarg.time_gran);
+ fuse_debug(" map_alignment=%u\n", outarg.map_alignment);
if (arg->minor < 5)
outargsize = FUSE_COMPAT_INIT_OUT_SIZE;
else if (arg->minor < 23)
@@ -2440,13 +2426,11 @@ void fuse_session_process_buf_int(struct fuse_session *se,
in = fuse_mbuf_iter_advance(&iter, sizeof(*in));
assert(in); /* caller guarantees the input buffer is large enough */
- if (se->debug) {
- fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n",
- (unsigned long long) in->unique,
- opname((enum fuse_opcode) in->opcode), in->opcode,
- (unsigned long long) in->nodeid, buf->size,
- in->pid);
- }
+ fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n",
+ (unsigned long long) in->unique,
+ opname((enum fuse_opcode) in->opcode), in->opcode,
+ (unsigned long long) in->nodeid, buf->size,
+ in->pid);
req = fuse_ll_alloc_req(se);
if (req == NULL) {
@@ -2493,8 +2477,7 @@ void fuse_session_process_buf_int(struct fuse_session *se,
// TODO: This is after a hard reboot typically, we need to do
// a destroy, but we can't reply to this request yet so
// we can't use do_destroy
- if (se->debug)
- fuse_debug("%s: reinit\n", __func__);
+ fuse_debug("%s: reinit\n", __func__);
se->got_destroy = 1;
se->got_init = 0;
if (se->op.destroy)
diff --git a/contrib/virtiofsd/fuse_lowlevel.h b/contrib/virtiofsd/fuse_lowlevel.h
index e761d8d0e5ec..b441d3dfedeb 100644
--- a/contrib/virtiofsd/fuse_lowlevel.h
+++ b/contrib/virtiofsd/fuse_lowlevel.h
@@ -1798,6 +1798,7 @@ struct fuse_cmdline_opts {
int show_help;
int clone_fd;
int syslog;
+ int log_level;
unsigned int max_idle_threads;
};
diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c
index 72ddf703c9d4..5b3174e4c74c 100644
--- a/contrib/virtiofsd/fuse_virtio.c
+++ b/contrib/virtiofsd/fuse_virtio.c
@@ -223,9 +223,8 @@ int virtio_send_msg(struct fuse_session *se, struct fuse_chan *ch,
unsigned int in_num = elem->in_num;
struct iovec *in_sg = elem->in_sg;
size_t in_len = iov_length(in_sg, in_num);
- if (se->debug)
- fuse_debug("%s: elem %d: with %d in desc of length %zd\n",
- __func__, elem->index, in_num, in_len);
+ fuse_debug("%s: elem %d: with %d in desc of length %zd\n",
+ __func__, elem->index, in_num, in_len);
/* The elem should have room for a 'fuse_out_header' (out from fuse)
* plus the data based on the len in the header.
@@ -286,9 +285,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch,
out->len = tosend_len;
- if (se->debug)
- fuse_debug("%s: count=%d len=%zd iov_len=%zd \n",
- __func__, count, len, iov_len);
+ fuse_debug("%s: count=%d len=%zd iov_len=%zd \n",
+ __func__, count, len, iov_len);
/* unique == 0 is notification which we don't support */
assert (out->unique);
@@ -301,9 +299,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch,
struct iovec *in_sg = elem->in_sg;
size_t in_len = iov_length(in_sg, in_num);
size_t in_len_writeable = iov_length(in_sg, in_num - bad_in_num);
- if (se->debug)
- fuse_debug("%s: elem %d: with %d in desc of length %zd\n",
- __func__, elem->index, in_num, in_len);
+ fuse_debug("%s: elem %d: with %d in desc of length %zd\n",
+ __func__, elem->index, in_num, in_len);
/* The elem should have room for a 'fuse_out_header' (out from fuse)
* plus the data based on the len in the header.
@@ -356,23 +353,19 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch,
for (i = 0, in_sg_left = 0; i < in_sg_cpy_count; i++) {
in_sg_left += in_sg_ptr[i].iov_len;
}
- if (se->debug)
- fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n",
- __func__, skip_size, in_sg_cpy_count,
- in_sg_left);
+ fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n",
+ __func__, skip_size, in_sg_cpy_count, in_sg_left);
ret = preadv(buf->buf[0].fd, in_sg_ptr, in_sg_cpy_count, buf->buf[0].pos);
- if (se->debug)
- fuse_debug("%s: preadv_res=%d(%s) len=%zd\n",
- __func__, ret, strerror(errno), len);
+ fuse_debug("%s: preadv_res=%d(%s) len=%zd\n",
+ __func__, ret, strerror(errno), len);
if (ret == -1) {
ret = errno;
free(in_sg_cpy);
goto err;
}
if (ret < len && ret) {
- if (se->debug)
- fuse_debug("%s: ret < len\n", __func__);
+ fuse_debug("%s: ret < len\n", __func__);
/* Skip over this much next time around */
skip_size = ret;
buf->buf[0].pos += ret;
@@ -383,14 +376,12 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch,
}
if (!ret) {
/* EOF case? */
- if (se->debug)
- fuse_debug("%s: !ret in_sg_left=%zd\n",
- __func__, in_sg_left);
+ fuse_debug("%s: !ret in_sg_left=%zd\n",
+ __func__, in_sg_left);
break;
}
if (ret != len) {
- if (se->debug)
- fuse_debug("%s: ret!=len\n", __func__);
+ fuse_debug("%s: ret!=len\n", __func__);
ret = EIO;
free(in_sg_cpy);
goto err;
@@ -410,11 +401,10 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch,
msg.len[0] = len;
}
int64_t req_res =fuse_virtio_io(se, &msg, buf->buf[0].fd);
- if (se->debug)
- fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n",
- __func__, len, bad_in_num,
- buf->buf[0].pos,
- in_sg_ptr[0].iov_base, req_res);
+ fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n",
+ __func__, len, bad_in_num,
+ buf->buf[0].pos,
+ in_sg_ptr[0].iov_base, req_res);
if (req_res > 0) {
len -= msg.len[0];
buf->buf[0].pos += msg.len[0];
@@ -488,11 +478,10 @@ static void fv_queue_worker(gpointer data, gpointer user_data)
struct iovec *out_sg = elem->out_sg;
size_t out_len = iov_length(out_sg, out_num);
size_t out_len_readable = iov_length(out_sg, out_num_readable);
- if (se->debug)
- fuse_debug("%s: elem %d: with %d out desc of length %zd"
- " bad_in_num=%u bad_out_num=%u\n",
- __func__, elem->index, out_num,
- out_len, req->bad_in_num, req->bad_out_num);
+ fuse_debug("%s: elem %d: with %d out desc of length %zd"
+ " bad_in_num=%u bad_out_num=%u\n",
+ __func__, elem->index, out_num,
+ out_len, req->bad_in_num, req->bad_out_num);
/* The elem should contain a 'fuse_in_header' (in to fuse)
* plus the data based on the len in the header.
@@ -555,11 +544,9 @@ static void fv_queue_worker(gpointer data, gpointer user_data)
((struct fuse_in_header *)fbuf.mem)->opcode ==
FUSE_READ &&
out_sg[1].iov_len == sizeof(struct fuse_read_in)) {
- if (se->debug) {
- fuse_debug("Unmappable read case "
- "in_num=%d bad_in_num=%d\n",
- elem->in_num, req->bad_in_num);
- }
+ fuse_debug("Unmappable read case "
+ "in_num=%d bad_in_num=%d\n",
+ elem->in_num, req->bad_in_num);
handled_unmappable = true;
}
@@ -581,8 +568,7 @@ static void fv_queue_worker(gpointer data, gpointer user_data)
// data, we can just do it straight out of guest memory
// but we must sitll copy the headers in case the guest
// was nasty and changed them while we were using them.
- if (se->debug)
- fuse_debug("%s: Write special case\n", __func__);
+ fuse_debug("%s: Write special case\n", __func__);
// copy the fuse_write_in header afte rthe fuse_in_header
fbuf.mem += out_sg->iov_len;
@@ -636,10 +622,8 @@ static void fv_queue_worker(gpointer data, gpointer user_data)
if (!req->reply_sent) {
struct VuVirtq *q = vu_get_queue(dev, qi->qidx);
- if (se->debug) {
- fuse_debug("%s: elem %d no reply sent\n",
- __func__, elem->index);
- }
+ fuse_debug("%s: elem %d no reply sent\n",
+ __func__, elem->index);
pthread_rwlock_rdlock(&qi->virtio_dev->vu_dispatch_rwlock);
pthread_mutex_lock(&qi->vq_lock);
@@ -683,8 +667,7 @@ static void *fv_queue_thread(void *opaque)
pf[1].events = POLLIN;
pf[1].revents = 0;
- if (qi->virtio_dev->se->debug)
- fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx);
+ fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx);
int poll_res = ppoll(pf, 2, NULL, NULL);
if (poll_res == -1) {
@@ -712,9 +695,8 @@ static void *fv_queue_thread(void *opaque)
break;
}
assert(pf[0].revents & POLLIN);
- if (qi->virtio_dev->se->debug)
- fuse_debug("%s: Got queue event on Queue %d\n",
- __func__, qi->qidx);
+ fuse_debug("%s: Got queue event on Queue %d\n",
+ __func__, qi->qidx);
eventfd_t evalue;
if (eventfd_read(qi->kick_fd, &evalue)) {
@@ -728,15 +710,13 @@ static void *fv_queue_thread(void *opaque)
pthread_mutex_lock(&qi->vq_lock);
- if (se->debug) {
- /* out is from guest, in is too guest */
- unsigned int in_bytes, out_bytes;
- vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0);
+ /* out is from guest, in is too guest */
+ unsigned int in_bytes, out_bytes;
+ vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0);
- fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n",
- __func__, qi->qidx, (size_t)evalue, in_bytes,
- out_bytes);
- }
+ fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n",
+ __func__, qi->qidx, (size_t)evalue, in_bytes,
+ out_bytes);
while (1) {
unsigned int bad_in_num = 0, bad_out_num = 0;
@@ -871,8 +851,7 @@ int virtio_loop(struct fuse_session *se)
pf[0].events = POLLIN;
pf[0].revents = 0;
- if (se->debug)
- fuse_debug("%s: Waiting for VU event\n", __func__);
+ fuse_debug("%s: Waiting for VU event\n", __func__);
int poll_res = ppoll(pf, 1, NULL, NULL);
if (poll_res == -1) {
@@ -890,8 +869,7 @@ int virtio_loop(struct fuse_session *se)
break;
}
assert(pf[0].revents & POLLIN);
- if (se->debug)
- fuse_debug("%s: Got VU event\n", __func__);
+ fuse_debug("%s: Got VU event\n", __func__);
/* Mutual exclusion with fv_queue_thread() */
ret = pthread_rwlock_wrlock(&se->virtio_dev->vu_dispatch_rwlock);
@@ -1058,9 +1036,7 @@ ssize_t fuse_virtio_write(fuse_req_t req,
msg.flags[0] = VHOST_USER_FS_FLAG_MAP_W;
int64_t result = fuse_virtio_io(req->se, &msg, dst->fd);
- if (req->se->debug) {
- fuse_debug("%s: result=%ld\n", __func__, result);
- }
+ fuse_debug("%s: result=%ld\n", __func__, result);
return result;
}
diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c
index 5eae1f530aae..dc80100e8594 100644
--- a/contrib/virtiofsd/helper.c
+++ b/contrib/virtiofsd/helper.c
@@ -27,6 +27,8 @@
#define FUSE_HELPER_OPT(t, p) \
{ t, offsetof(struct fuse_cmdline_opts, p), 1 }
+#define FUSE_HELPER_OPT_VALUE(t, p, v) \
+ { t, offsetof(struct fuse_cmdline_opts, p), v }
static const struct fuse_opt fuse_helper_opts[] = {
FUSE_HELPER_OPT("-h", show_help),
@@ -50,6 +52,10 @@ static const struct fuse_opt fuse_helper_opts[] = {
FUSE_HELPER_OPT("clone_fd", clone_fd),
FUSE_HELPER_OPT("max_idle_threads=%u", max_idle_threads),
FUSE_HELPER_OPT("--syslog", syslog),
+ FUSE_HELPER_OPT_VALUE("log_level=debug", log_level, LOG_DEBUG),
+ FUSE_HELPER_OPT_VALUE("log_level=info", log_level, LOG_INFO),
+ FUSE_HELPER_OPT_VALUE("log_level=warn", log_level, LOG_WARNING),
+ FUSE_HELPER_OPT_VALUE("log_level=err", log_level, LOG_ERR),
FUSE_OPT_END
};
@@ -137,7 +143,9 @@ void fuse_cmdline_help(void)
" -o clone_fd use separate fuse device fd for each thread\n"
" (may improve performance)\n"
" -o max_idle_threads the maximum number of idle worker threads\n"
- " allowed (default: 10)\n");
+ " allowed (default: 10)\n"
+ " -o log_level=<level> log level, default to \"info\"\n"
+ " level could be one of \"debug, info, warn, err\"\n");
}
static int fuse_helper_opt_proc(void *data, const char *arg, int key,
diff --git a/contrib/virtiofsd/passthrough_ll.c b/contrib/virtiofsd/passthrough_ll.c
index 321bbb20be65..583e9685161f 100644
--- a/contrib/virtiofsd/passthrough_ll.c
+++ b/contrib/virtiofsd/passthrough_ll.c
@@ -36,6 +36,7 @@
#include "fuse_virtio.h"
#include "fuse_lowlevel.h"
+#include "fuse_log.h"
#include <unistd.h>
#include <stdlib.h>
#include <stdio.h>
@@ -421,11 +422,6 @@ static int lo_fd(fuse_req_t req, fuse_ino_t ino)
return fd;
}
-static bool lo_debug(fuse_req_t req)
-{
- return lo_data(req)->debug != 0;
-}
-
static void lo_init(void *userdata,
struct fuse_conn_info *conn)
{
@@ -436,18 +432,15 @@ static void lo_init(void *userdata,
if (lo->writeback &&
conn->capable & FUSE_CAP_WRITEBACK_CACHE) {
- if (lo->debug)
- fuse_debug("lo_init: activating writeback\n");
+ fuse_debug("lo_init: activating writeback\n");
conn->want |= FUSE_CAP_WRITEBACK_CACHE;
}
if (conn->capable & FUSE_CAP_FLOCK_LOCKS) {
if (lo->flock) {
- if (lo->debug)
- fuse_debug("lo_init: activating flock locks\n");
+ fuse_debug("lo_init: activating flock locks\n");
conn->want |= FUSE_CAP_FLOCK_LOCKS;
} else {
- if (lo->debug)
- fuse_debug("lo_init: disabling flock locks\n");
+ fuse_debug("lo_init: disabling flock locks\n");
conn->want &= ~FUSE_CAP_FLOCK_LOCKS;
}
}
@@ -455,20 +448,17 @@ static void lo_init(void *userdata,
if (conn->capable & FUSE_CAP_POSIX_LOCKS) {
if (lo->posix_lock) {
- if (lo->debug)
- fuse_debug("lo_init: activating posix locks\n");
+ fuse_debug("lo_init: activating posix locks\n");
conn->want |= FUSE_CAP_POSIX_LOCKS;
} else {
- if (lo->debug)
- fuse_debug("lo_init: disabling posix locks\n");
+ fuse_debug("lo_init: disabling posix locks\n");
conn->want &= ~FUSE_CAP_POSIX_LOCKS;
}
}
if ((lo->cache == CACHE_NONE && !lo->readdirplus_set) ||
lo->readdirplus_clear || lo->shared) {
- if (lo->debug)
- fuse_debug("lo_init: disabling readdirplus\n");
+ fuse_debug("lo_init: disabling readdirplus\n");
conn->want &= ~FUSE_CAP_READDIRPLUS;
}
}
@@ -909,12 +899,11 @@ static int lo_do_lookup(fuse_req_t req, fuse_ino_t parent, const char *name,
lo_inode_put(lo, &inode);
lo_inode_put(lo, &dir);
- if (lo_debug(req))
- fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n",
- (unsigned long long) parent, name,
- (unsigned long long) e->ino,
- (unsigned long long) e->version_offset,
- (unsigned long long) e->initial_version);
+ fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n",
+ (unsigned long long) parent, name,
+ (unsigned long long) e->ino,
+ (unsigned long long) e->version_offset,
+ (unsigned long long) e->initial_version);
return 0;
@@ -932,9 +921,7 @@ static void lo_lookup(fuse_req_t req, fuse_ino_t parent, const char *name)
struct fuse_entry_param e;
int err;
- if (lo_debug(req))
- fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n",
- parent, name);
+ fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", parent, name);
/* Don't use is_safe_path_component(), allow "." and ".." for NFS export
* support.
@@ -1040,10 +1027,9 @@ static void lo_mknod_symlink(fuse_req_t req, fuse_ino_t parent,
if (saverr)
goto out;
- if (lo_debug(req))
- fuse_debug(" %lli/%s -> %lli\n",
- (unsigned long long) parent, name,
- (unsigned long long) e.ino);
+ fuse_debug(" %lli/%s -> %lli\n",
+ (unsigned long long) parent, name,
+ (unsigned long long) e.ino);
fuse_reply_entry(req, &e, lo->shared);
lo_inode_put(lo, &dir);
@@ -1149,10 +1135,9 @@ static void lo_link(fuse_req_t req, fuse_ino_t ino, fuse_ino_t parent,
update_version(lo, inode);
update_version(lo, parent_inode);
- if (lo_debug(req))
- fuse_debug(" %lli/%s -> %lli\n",
- (unsigned long long) parent, name,
- (unsigned long long) e.ino);
+ fuse_debug(" %lli/%s -> %lli\n",
+ (unsigned long long) parent, name,
+ (unsigned long long) e.ino);
fuse_reply_entry(req, &e, lo->shared);
lo_inode_put(lo, &parent_inode);
@@ -1355,12 +1340,10 @@ static void lo_forget_one(fuse_req_t req, fuse_ino_t ino, uint64_t nlookup)
if (!inode)
return;
- if (lo_debug(req)) {
- fuse_debug(" forget %lli %lli -%lli\n",
- (unsigned long long) ino,
- (unsigned long long) inode->nlookup,
- (unsigned long long) nlookup);
- }
+ fuse_debug(" forget %lli %lli -%lli\n",
+ (unsigned long long) ino,
+ (unsigned long long) inode->nlookup,
+ (unsigned long long) nlookup);
unref_inode(lo, inode, nlookup);
lo_inode_put(lo, &inode);
@@ -1642,9 +1625,7 @@ static void lo_create(fuse_req_t req, fuse_ino_t parent, const char *name,
int err;
struct lo_cred old = {};
- if (lo_debug(req))
- fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n",
- parent, name);
+ fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", parent, name);
if (!is_safe_path_component(name)) {
fuse_reply_err(req, EINVAL);
@@ -1744,11 +1725,10 @@ static void lo_getlk(fuse_req_t req, fuse_ino_t ino,
struct lo_inode_plock *plock;
int ret, saverr = 0;
- if (lo_debug(req))
- fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)"
- " owner=0x%lx, l_type=%d l_start=0x%lx"
- " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner,
- lock->l_type, lock->l_start, lock->l_len);
+ fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)"
+ " owner=0x%lx, l_type=%d l_start=0x%lx"
+ " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner,
+ lock->l_type, lock->l_start, lock->l_len);
inode = lo_inode(req, ino);
if (!inode) {
@@ -1786,12 +1766,11 @@ static void lo_setlk(fuse_req_t req, fuse_ino_t ino,
struct lo_inode_plock *plock;
int ret, saverr = 0;
- if (lo_debug(req))
- fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)"
- " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d"
- " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags,
- lock->l_type, lock->l_pid, fi->lock_owner, sleep,
- lock->l_whence, lock->l_start, lock->l_len);
+ fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)"
+ " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d"
+ " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags,
+ lock->l_type, lock->l_pid, fi->lock_owner, sleep,
+ lock->l_whence, lock->l_start, lock->l_len);
if (sleep) {
fuse_reply_err(req, EOPNOTSUPP);
@@ -1860,9 +1839,7 @@ static void lo_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info *fi)
char buf[64];
struct lo_data *lo = lo_data(req);
- if (lo_debug(req))
- fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n",
- ino, fi->flags);
+ fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", ino, fi->flags);
/* With writeback cache, kernel may send read requests even
when userspace opened write-only */
@@ -1965,9 +1942,7 @@ static void lo_fsync(fuse_req_t req, fuse_ino_t ino, int datasync,
int fd;
char *buf;
- if (lo_debug(req))
- fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino,
- (void *)fi);
+ fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, (void *)fi);
if (!fi) {
res = asprintf(&buf, "%i", lo_fd(req, ino));
@@ -1995,9 +1970,8 @@ static void lo_read(fuse_req_t req, fuse_ino_t ino, size_t size,
{
struct fuse_bufvec buf = FUSE_BUFVEC_INIT(size);
- if (lo_debug(req))
- fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, "
- "off=%lu)\n", ino, size, (unsigned long) offset);
+ fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, "
+ "off=%lu)\n", ino, size, (unsigned long) offset);
buf.buf[0].flags = FUSE_BUF_IS_FD | FUSE_BUF_FD_SEEK;
buf.buf[0].fd = lo_fi_fd(req, fi);
@@ -2019,9 +1993,8 @@ static void lo_write_buf(fuse_req_t req, fuse_ino_t ino,
out_buf.buf[0].fd = lo_fi_fd(req, fi);
out_buf.buf[0].pos = off;
- if (lo_debug(req))
- fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n",
- ino, out_buf.buf[0].size, (unsigned long) off);
+ fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n",
+ ino, out_buf.buf[0].size, (unsigned long) off);
res = fuse_buf_copy(req, &out_buf, in_buf, 0);
if(res < 0) {
@@ -2105,10 +2078,8 @@ static void lo_getxattr(fuse_req_t req, fuse_ino_t ino, const char *name,
if (!lo_data(req)->xattr)
goto out;
- if (lo_debug(req)) {
- fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n",
- ino, name, size);
- }
+ fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n",
+ ino, name, size);
if (inode->is_symlink) {
/* Sorry, no race free way to getxattr on symlink. */
@@ -2180,10 +2151,7 @@ static void lo_listxattr(fuse_req_t req, fuse_ino_t ino, size_t size)
if (!lo_data(req)->xattr)
goto out;
- if (lo_debug(req)) {
- fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n",
- ino, size);
- }
+ fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", ino, size);
if (inode->is_symlink) {
/* Sorry, no race free way to listxattr on symlink. */
@@ -2255,10 +2223,8 @@ static void lo_setxattr(fuse_req_t req, fuse_ino_t ino, const char *name,
if (!lo_data(req)->xattr)
goto out;
- if (lo_debug(req)) {
- fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n",
- ino, name, value, size);
- }
+ fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n",
+ ino, name, value, size);
if (inode->is_symlink) {
/* Sorry, no race free way to removexattr on symlink. */
@@ -2306,10 +2272,7 @@ static void lo_removexattr(fuse_req_t req, fuse_ino_t ino, const char *name)
if (!lo_data(req)->xattr)
goto out;
- if (lo_debug(req)) {
- fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n",
- ino, name);
- }
+ fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", ino, name);
if (inode->is_symlink) {
/* Sorry, no race free way to setxattr on symlink. */
@@ -2351,12 +2314,11 @@ static void lo_copy_file_range(fuse_req_t req, fuse_ino_t ino_in, off_t off_in,
in_fd = lo_fi_fd(req, fi_in);
out_fd = lo_fi_fd(req, fi_out);
- if (lo_debug(req))
- fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, "
- "off=%lu, ino=%" PRIu64 "/fd=%d, "
- "off=%lu, size=%zd, flags=0x%x)\n",
- ino_in, in_fd, off_in, ino_out, out_fd, off_out, len,
- flags);
+ fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, "
+ "off=%lu, ino=%" PRIu64 "/fd=%d, "
+ "off=%lu, size=%zd, flags=0x%x)\n",
+ ino_in, in_fd, off_in, ino_out, out_fd, off_out, len,
+ flags);
res = copy_file_range(in_fd, &off_in, out_fd, &off_out, len, flags);
if (res < 0)
@@ -2377,11 +2339,10 @@ static void lo_setupmapping(fuse_req_t req, fuse_ino_t ino, uint64_t foffset,
char *buf;
bool writable = flags & O_RDWR;
- if (lo_debug(req))
- fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p,"
- " foffset=%" PRIu64 ", len=%" PRIu64
- ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino,
- (void *)fi, foffset, len, moffset, flags);
+ fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p,"
+ " foffset=%" PRIu64 ", len=%" PRIu64
+ ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino,
+ (void *)fi, foffset, len, moffset, flags);
vhu_flags = VHOST_USER_FS_FLAG_MAP_R;
if (writable)
@@ -2878,7 +2839,16 @@ int main(int argc, char *argv[])
if (fuse_opt_parse(&args, &lo, lo_opts, NULL)== -1)
goto err_out1;
+ /*
+ * log_level is 0 if not configured via cmd options (0 is LOG_EMERG,
+ * and we don't use this log level).
+ */
+ if (opts.log_level != 0)
+ current_log_level = opts.log_level;
lo.debug = opts.debug;
+ if (lo.debug)
+ current_log_level = LOG_DEBUG;
+
if (lo.source) {
struct stat stat;
int res;
--
2.14.4.44.g2045bb6
^ permalink raw reply related [flat|nested] 12+ messages in thread* [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra 2019-08-09 8:25 [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough Eryu Guan @ 2019-08-09 8:25 ` Eryu Guan 2019-08-09 9:40 ` piaojun 2019-08-16 16:52 ` Dr. David Alan Gilbert 2019-08-09 9:34 ` [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough piaojun 1 sibling, 2 replies; 12+ messages in thread From: Eryu Guan @ 2019-08-09 8:25 UTC (permalink / raw) To: virtio-fs Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> --- contrib/virtiofsd/fuse_lowlevel.c | 6 +++--- contrib/virtiofsd/fuse_signals.c | 7 +++++-- contrib/virtiofsd/fuse_virtio.c | 16 ++++++++-------- contrib/virtiofsd/helper.c | 6 +++--- 4 files changed, 19 insertions(+), 16 deletions(-) diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c index 7eec2680b6de..8ef800239f1e 100644 --- a/contrib/virtiofsd/fuse_lowlevel.c +++ b/contrib/virtiofsd/fuse_lowlevel.c @@ -1901,15 +1901,15 @@ static void do_removemapping(fuse_req_t req, fuse_ino_t nodeid, arg = fuse_mbuf_iter_advance(iter, sizeof(*arg)); if (!arg || arg->count <= 0) { - fprintf(stderr, "do_removemapping: invalid arg %p\n", arg); + fuse_err("do_removemapping: invalid arg %p\n", arg); fuse_reply_err(req, EINVAL); return; } one = fuse_mbuf_iter_advance(iter, arg->count * sizeof(*one)); if (!one) { - fprintf(stderr, "do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", - arg->count, sizeof(*one), iter->size, iter->pos); + fuse_err("do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", + arg->count, sizeof(*one), iter->size, iter->pos); fuse_reply_err(req, EINVAL); return; } diff --git a/contrib/virtiofsd/fuse_signals.c b/contrib/virtiofsd/fuse_signals.c index aa3bdba7daaf..9d34f6b04025 100644 --- a/contrib/virtiofsd/fuse_signals.c +++ b/contrib/virtiofsd/fuse_signals.c @@ -12,6 +12,7 @@ #include "fuse_log.h" #include "fuse_lowlevel.h" +#include <errno.h> #include <stdio.h> #include <string.h> #include <signal.h> @@ -47,13 +48,15 @@ static int set_one_signal_handler(int sig, void (*handler)(int), int remove) sa.sa_flags = 0; if (sigaction(sig, NULL, &old_sa) == -1) { - perror("fuse: cannot get old signal handler"); + fuse_err("fuse: cannot get old signal handler: %s\n", + strerror(errno)); return -1; } if (old_sa.sa_handler == (remove ? handler : SIG_DFL) && sigaction(sig, &sa, NULL) == -1) { - perror("fuse: cannot set signal handler"); + fuse_err("fuse: cannot set signal handler: %s\n", + strerror(errno)); return -1; } return 0; diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c index 5b3174e4c74c..2ce0a9cf816e 100644 --- a/contrib/virtiofsd/fuse_virtio.c +++ b/contrib/virtiofsd/fuse_virtio.c @@ -675,7 +675,7 @@ static void *fv_queue_thread(void *opaque) fuse_info("%s: ppoll interrupted, going around\n", __func__); continue; } - perror("fv_queue_thread ppoll"); + fuse_err("fv_queue_thread ppoll: %s\n", strerror(errno)); break; } assert(poll_res >= 1); @@ -700,7 +700,7 @@ static void *fv_queue_thread(void *opaque) eventfd_t evalue; if (eventfd_read(qi->kick_fd, &evalue)) { - perror("Eventfd_read for queue"); + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); break; } @@ -805,7 +805,7 @@ static void fv_queue_set_started(VuDev *dev, int qidx, bool started) /* Kill the thread */ if (eventfd_write(ourqi->kill_fd, 1)) { - perror("Eventfd_read for queue"); + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); } ret = pthread_join(ourqi->thread, NULL); if (ret) { @@ -859,7 +859,7 @@ int virtio_loop(struct fuse_session *se) fuse_info("%s: ppoll interrupted, going around\n", __func__); continue; } - perror("virtio_loop ppoll"); + fuse_err("virtio_loop ppoll: %s\n", strerror(errno)); break; } assert(poll_res == 1); @@ -913,18 +913,18 @@ static int fv_create_listen_socket(struct fuse_session *se) int listen_sock = socket(AF_UNIX, SOCK_STREAM, 0); if (listen_sock == -1) { - perror("vhost socket creation"); + fuse_err("vhost socket creation: %s\n", strerror(errno)); return -1; } un.sun_family = AF_UNIX; if (bind(listen_sock, (struct sockaddr *) &un, addr_len) == -1) { - perror("vhost socket bind"); + fuse_err("vhost socket bind: %s\n", strerror(errno)); return -1; } if (listen(listen_sock, 1) == -1) { - perror("vhost socket listen"); + fuse_err("vhost socket listen: %s\n", strerror(errno)); return -1; } @@ -949,7 +949,7 @@ int virtio_session_mount(struct fuse_session *se) fuse_err("%s: Waiting for vhost-user socket connection...\n", __func__); int data_sock = accept(se->vu_listen_fd, NULL, NULL); if (data_sock == -1) { - perror("vhost socket accept"); + fuse_err("vhost socket accept: %s\n", strerror(errno)); close(se->vu_listen_fd); return -1; } diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c index dc80100e8594..4c7145208028 100644 --- a/contrib/virtiofsd/helper.c +++ b/contrib/virtiofsd/helper.c @@ -189,7 +189,7 @@ int fuse_daemonize(int foreground) char completed; if (pipe(waiter)) { - perror("fuse_daemonize: pipe"); + fuse_err("fuse_daemonize: pipe: %s\n", strerror(errno)); return -1; } @@ -199,7 +199,7 @@ int fuse_daemonize(int foreground) */ switch(fork()) { case -1: - perror("fuse_daemonize: fork"); + fuse_err("fuse_daemonize: fork: %s\n", strerror(errno)); return -1; case 0: break; @@ -209,7 +209,7 @@ int fuse_daemonize(int foreground) } if (setsid() == -1) { - perror("fuse_daemonize: setsid"); + fuse_err("fuse_daemonize: setsid: %s\n", strerror(errno)); return -1; } -- 2.14.4.44.g2045bb6 ^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra 2019-08-09 8:25 ` [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra Eryu Guan @ 2019-08-09 9:40 ` piaojun 2019-08-11 13:21 ` Eryu Guan 2019-08-16 16:52 ` Dr. David Alan Gilbert 1 sibling, 1 reply; 12+ messages in thread From: piaojun @ 2019-08-09 9:40 UTC (permalink / raw) To: Eryu Guan, virtio-fs Hi Eryu, Could fuse_err() print to stderr as well? Jun On 2019/8/9 16:25, Eryu Guan wrote: > Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> > --- > contrib/virtiofsd/fuse_lowlevel.c | 6 +++--- > contrib/virtiofsd/fuse_signals.c | 7 +++++-- > contrib/virtiofsd/fuse_virtio.c | 16 ++++++++-------- > contrib/virtiofsd/helper.c | 6 +++--- > 4 files changed, 19 insertions(+), 16 deletions(-) > > diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > index 7eec2680b6de..8ef800239f1e 100644 > --- a/contrib/virtiofsd/fuse_lowlevel.c > +++ b/contrib/virtiofsd/fuse_lowlevel.c > @@ -1901,15 +1901,15 @@ static void do_removemapping(fuse_req_t req, fuse_ino_t nodeid, > > arg = fuse_mbuf_iter_advance(iter, sizeof(*arg)); > if (!arg || arg->count <= 0) { > - fprintf(stderr, "do_removemapping: invalid arg %p\n", arg); > + fuse_err("do_removemapping: invalid arg %p\n", arg); > fuse_reply_err(req, EINVAL); > return; > } > > one = fuse_mbuf_iter_advance(iter, arg->count * sizeof(*one)); > if (!one) { > - fprintf(stderr, "do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", > - arg->count, sizeof(*one), iter->size, iter->pos); > + fuse_err("do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", > + arg->count, sizeof(*one), iter->size, iter->pos); > fuse_reply_err(req, EINVAL); > return; > } > diff --git a/contrib/virtiofsd/fuse_signals.c b/contrib/virtiofsd/fuse_signals.c > index aa3bdba7daaf..9d34f6b04025 100644 > --- a/contrib/virtiofsd/fuse_signals.c > +++ b/contrib/virtiofsd/fuse_signals.c > @@ -12,6 +12,7 @@ > #include "fuse_log.h" > #include "fuse_lowlevel.h" > > +#include <errno.h> > #include <stdio.h> > #include <string.h> > #include <signal.h> > @@ -47,13 +48,15 @@ static int set_one_signal_handler(int sig, void (*handler)(int), int remove) > sa.sa_flags = 0; > > if (sigaction(sig, NULL, &old_sa) == -1) { > - perror("fuse: cannot get old signal handler"); > + fuse_err("fuse: cannot get old signal handler: %s\n", > + strerror(errno)); > return -1; > } > > if (old_sa.sa_handler == (remove ? handler : SIG_DFL) && > sigaction(sig, &sa, NULL) == -1) { > - perror("fuse: cannot set signal handler"); > + fuse_err("fuse: cannot set signal handler: %s\n", > + strerror(errno)); > return -1; > } > return 0; > diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > index 5b3174e4c74c..2ce0a9cf816e 100644 > --- a/contrib/virtiofsd/fuse_virtio.c > +++ b/contrib/virtiofsd/fuse_virtio.c > @@ -675,7 +675,7 @@ static void *fv_queue_thread(void *opaque) > fuse_info("%s: ppoll interrupted, going around\n", __func__); > continue; > } > - perror("fv_queue_thread ppoll"); > + fuse_err("fv_queue_thread ppoll: %s\n", strerror(errno)); > break; > } > assert(poll_res >= 1); > @@ -700,7 +700,7 @@ static void *fv_queue_thread(void *opaque) > > eventfd_t evalue; > if (eventfd_read(qi->kick_fd, &evalue)) { > - perror("Eventfd_read for queue"); > + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); > break; > } > > @@ -805,7 +805,7 @@ static void fv_queue_set_started(VuDev *dev, int qidx, bool started) > > /* Kill the thread */ > if (eventfd_write(ourqi->kill_fd, 1)) { > - perror("Eventfd_read for queue"); > + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); > } > ret = pthread_join(ourqi->thread, NULL); > if (ret) { > @@ -859,7 +859,7 @@ int virtio_loop(struct fuse_session *se) > fuse_info("%s: ppoll interrupted, going around\n", __func__); > continue; > } > - perror("virtio_loop ppoll"); > + fuse_err("virtio_loop ppoll: %s\n", strerror(errno)); > break; > } > assert(poll_res == 1); > @@ -913,18 +913,18 @@ static int fv_create_listen_socket(struct fuse_session *se) > > int listen_sock = socket(AF_UNIX, SOCK_STREAM, 0); > if (listen_sock == -1) { > - perror("vhost socket creation"); > + fuse_err("vhost socket creation: %s\n", strerror(errno)); > return -1; > } > un.sun_family = AF_UNIX; > > if (bind(listen_sock, (struct sockaddr *) &un, addr_len) == -1) { > - perror("vhost socket bind"); > + fuse_err("vhost socket bind: %s\n", strerror(errno)); > return -1; > } > > if (listen(listen_sock, 1) == -1) { > - perror("vhost socket listen"); > + fuse_err("vhost socket listen: %s\n", strerror(errno)); > return -1; > } > > @@ -949,7 +949,7 @@ int virtio_session_mount(struct fuse_session *se) > fuse_err("%s: Waiting for vhost-user socket connection...\n", __func__); > int data_sock = accept(se->vu_listen_fd, NULL, NULL); > if (data_sock == -1) { > - perror("vhost socket accept"); > + fuse_err("vhost socket accept: %s\n", strerror(errno)); > close(se->vu_listen_fd); > return -1; > } > diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > index dc80100e8594..4c7145208028 100644 > --- a/contrib/virtiofsd/helper.c > +++ b/contrib/virtiofsd/helper.c > @@ -189,7 +189,7 @@ int fuse_daemonize(int foreground) > char completed; > > if (pipe(waiter)) { > - perror("fuse_daemonize: pipe"); > + fuse_err("fuse_daemonize: pipe: %s\n", strerror(errno)); > return -1; > } > > @@ -199,7 +199,7 @@ int fuse_daemonize(int foreground) > */ > switch(fork()) { > case -1: > - perror("fuse_daemonize: fork"); > + fuse_err("fuse_daemonize: fork: %s\n", strerror(errno)); > return -1; > case 0: > break; > @@ -209,7 +209,7 @@ int fuse_daemonize(int foreground) > } > > if (setsid() == -1) { > - perror("fuse_daemonize: setsid"); > + fuse_err("fuse_daemonize: setsid: %s\n", strerror(errno)); > return -1; > } > > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra 2019-08-09 9:40 ` piaojun @ 2019-08-11 13:21 ` Eryu Guan 2019-08-11 14:12 ` piaojun 0 siblings, 1 reply; 12+ messages in thread From: Eryu Guan @ 2019-08-11 13:21 UTC (permalink / raw) To: piaojun; +Cc: virtio-fs On Fri, Aug 09, 2019 at 05:40:56PM +0800, piaojun wrote: > Hi Eryu, > > Could fuse_err() print to stderr as well? Yes, when "--syslog" is not used :) Thanks, Eryu > > Jun > > On 2019/8/9 16:25, Eryu Guan wrote: > > Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> > > --- > > contrib/virtiofsd/fuse_lowlevel.c | 6 +++--- > > contrib/virtiofsd/fuse_signals.c | 7 +++++-- > > contrib/virtiofsd/fuse_virtio.c | 16 ++++++++-------- > > contrib/virtiofsd/helper.c | 6 +++--- > > 4 files changed, 19 insertions(+), 16 deletions(-) > > > > diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > > index 7eec2680b6de..8ef800239f1e 100644 > > --- a/contrib/virtiofsd/fuse_lowlevel.c > > +++ b/contrib/virtiofsd/fuse_lowlevel.c > > @@ -1901,15 +1901,15 @@ static void do_removemapping(fuse_req_t req, fuse_ino_t nodeid, > > > > arg = fuse_mbuf_iter_advance(iter, sizeof(*arg)); > > if (!arg || arg->count <= 0) { > > - fprintf(stderr, "do_removemapping: invalid arg %p\n", arg); > > + fuse_err("do_removemapping: invalid arg %p\n", arg); > > fuse_reply_err(req, EINVAL); > > return; > > } > > > > one = fuse_mbuf_iter_advance(iter, arg->count * sizeof(*one)); > > if (!one) { > > - fprintf(stderr, "do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", > > - arg->count, sizeof(*one), iter->size, iter->pos); > > + fuse_err("do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", > > + arg->count, sizeof(*one), iter->size, iter->pos); > > fuse_reply_err(req, EINVAL); > > return; > > } > > diff --git a/contrib/virtiofsd/fuse_signals.c b/contrib/virtiofsd/fuse_signals.c > > index aa3bdba7daaf..9d34f6b04025 100644 > > --- a/contrib/virtiofsd/fuse_signals.c > > +++ b/contrib/virtiofsd/fuse_signals.c > > @@ -12,6 +12,7 @@ > > #include "fuse_log.h" > > #include "fuse_lowlevel.h" > > > > +#include <errno.h> > > #include <stdio.h> > > #include <string.h> > > #include <signal.h> > > @@ -47,13 +48,15 @@ static int set_one_signal_handler(int sig, void (*handler)(int), int remove) > > sa.sa_flags = 0; > > > > if (sigaction(sig, NULL, &old_sa) == -1) { > > - perror("fuse: cannot get old signal handler"); > > + fuse_err("fuse: cannot get old signal handler: %s\n", > > + strerror(errno)); > > return -1; > > } > > > > if (old_sa.sa_handler == (remove ? handler : SIG_DFL) && > > sigaction(sig, &sa, NULL) == -1) { > > - perror("fuse: cannot set signal handler"); > > + fuse_err("fuse: cannot set signal handler: %s\n", > > + strerror(errno)); > > return -1; > > } > > return 0; > > diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > > index 5b3174e4c74c..2ce0a9cf816e 100644 > > --- a/contrib/virtiofsd/fuse_virtio.c > > +++ b/contrib/virtiofsd/fuse_virtio.c > > @@ -675,7 +675,7 @@ static void *fv_queue_thread(void *opaque) > > fuse_info("%s: ppoll interrupted, going around\n", __func__); > > continue; > > } > > - perror("fv_queue_thread ppoll"); > > + fuse_err("fv_queue_thread ppoll: %s\n", strerror(errno)); > > break; > > } > > assert(poll_res >= 1); > > @@ -700,7 +700,7 @@ static void *fv_queue_thread(void *opaque) > > > > eventfd_t evalue; > > if (eventfd_read(qi->kick_fd, &evalue)) { > > - perror("Eventfd_read for queue"); > > + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); > > break; > > } > > > > @@ -805,7 +805,7 @@ static void fv_queue_set_started(VuDev *dev, int qidx, bool started) > > > > /* Kill the thread */ > > if (eventfd_write(ourqi->kill_fd, 1)) { > > - perror("Eventfd_read for queue"); > > + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); > > } > > ret = pthread_join(ourqi->thread, NULL); > > if (ret) { > > @@ -859,7 +859,7 @@ int virtio_loop(struct fuse_session *se) > > fuse_info("%s: ppoll interrupted, going around\n", __func__); > > continue; > > } > > - perror("virtio_loop ppoll"); > > + fuse_err("virtio_loop ppoll: %s\n", strerror(errno)); > > break; > > } > > assert(poll_res == 1); > > @@ -913,18 +913,18 @@ static int fv_create_listen_socket(struct fuse_session *se) > > > > int listen_sock = socket(AF_UNIX, SOCK_STREAM, 0); > > if (listen_sock == -1) { > > - perror("vhost socket creation"); > > + fuse_err("vhost socket creation: %s\n", strerror(errno)); > > return -1; > > } > > un.sun_family = AF_UNIX; > > > > if (bind(listen_sock, (struct sockaddr *) &un, addr_len) == -1) { > > - perror("vhost socket bind"); > > + fuse_err("vhost socket bind: %s\n", strerror(errno)); > > return -1; > > } > > > > if (listen(listen_sock, 1) == -1) { > > - perror("vhost socket listen"); > > + fuse_err("vhost socket listen: %s\n", strerror(errno)); > > return -1; > > } > > > > @@ -949,7 +949,7 @@ int virtio_session_mount(struct fuse_session *se) > > fuse_err("%s: Waiting for vhost-user socket connection...\n", __func__); > > int data_sock = accept(se->vu_listen_fd, NULL, NULL); > > if (data_sock == -1) { > > - perror("vhost socket accept"); > > + fuse_err("vhost socket accept: %s\n", strerror(errno)); > > close(se->vu_listen_fd); > > return -1; > > } > > diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > > index dc80100e8594..4c7145208028 100644 > > --- a/contrib/virtiofsd/helper.c > > +++ b/contrib/virtiofsd/helper.c > > @@ -189,7 +189,7 @@ int fuse_daemonize(int foreground) > > char completed; > > > > if (pipe(waiter)) { > > - perror("fuse_daemonize: pipe"); > > + fuse_err("fuse_daemonize: pipe: %s\n", strerror(errno)); > > return -1; > > } > > > > @@ -199,7 +199,7 @@ int fuse_daemonize(int foreground) > > */ > > switch(fork()) { > > case -1: > > - perror("fuse_daemonize: fork"); > > + fuse_err("fuse_daemonize: fork: %s\n", strerror(errno)); > > return -1; > > case 0: > > break; > > @@ -209,7 +209,7 @@ int fuse_daemonize(int foreground) > > } > > > > if (setsid() == -1) { > > - perror("fuse_daemonize: setsid"); > > + fuse_err("fuse_daemonize: setsid: %s\n", strerror(errno)); > > return -1; > > } > > > > > > _______________________________________________ > Virtio-fs mailing list > Virtio-fs@redhat.com > https://www.redhat.com/mailman/listinfo/virtio-fs ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra 2019-08-11 13:21 ` Eryu Guan @ 2019-08-11 14:12 ` piaojun 0 siblings, 0 replies; 12+ messages in thread From: piaojun @ 2019-08-11 14:12 UTC (permalink / raw) To: Eryu Guan; +Cc: virtio-fs On 2019/8/11 21:21, Eryu Guan wrote: > On Fri, Aug 09, 2019 at 05:40:56PM +0800, piaojun wrote: >> Hi Eryu, >> >> Could fuse_err() print to stderr as well? > > Yes, when "--syslog" is not used :) Got it, thanks. > > Thanks, > Eryu > >> >> Jun >> >> On 2019/8/9 16:25, Eryu Guan wrote: >>> Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> >>> --- >>> contrib/virtiofsd/fuse_lowlevel.c | 6 +++--- >>> contrib/virtiofsd/fuse_signals.c | 7 +++++-- >>> contrib/virtiofsd/fuse_virtio.c | 16 ++++++++-------- >>> contrib/virtiofsd/helper.c | 6 +++--- >>> 4 files changed, 19 insertions(+), 16 deletions(-) >>> >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c >>> index 7eec2680b6de..8ef800239f1e 100644 >>> --- a/contrib/virtiofsd/fuse_lowlevel.c >>> +++ b/contrib/virtiofsd/fuse_lowlevel.c >>> @@ -1901,15 +1901,15 @@ static void do_removemapping(fuse_req_t req, fuse_ino_t nodeid, >>> >>> arg = fuse_mbuf_iter_advance(iter, sizeof(*arg)); >>> if (!arg || arg->count <= 0) { >>> - fprintf(stderr, "do_removemapping: invalid arg %p\n", arg); >>> + fuse_err("do_removemapping: invalid arg %p\n", arg); >>> fuse_reply_err(req, EINVAL); >>> return; >>> } >>> >>> one = fuse_mbuf_iter_advance(iter, arg->count * sizeof(*one)); >>> if (!one) { >>> - fprintf(stderr, "do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", >>> - arg->count, sizeof(*one), iter->size, iter->pos); >>> + fuse_err("do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", >>> + arg->count, sizeof(*one), iter->size, iter->pos); >>> fuse_reply_err(req, EINVAL); >>> return; >>> } >>> diff --git a/contrib/virtiofsd/fuse_signals.c b/contrib/virtiofsd/fuse_signals.c >>> index aa3bdba7daaf..9d34f6b04025 100644 >>> --- a/contrib/virtiofsd/fuse_signals.c >>> +++ b/contrib/virtiofsd/fuse_signals.c >>> @@ -12,6 +12,7 @@ >>> #include "fuse_log.h" >>> #include "fuse_lowlevel.h" >>> >>> +#include <errno.h> >>> #include <stdio.h> >>> #include <string.h> >>> #include <signal.h> >>> @@ -47,13 +48,15 @@ static int set_one_signal_handler(int sig, void (*handler)(int), int remove) >>> sa.sa_flags = 0; >>> >>> if (sigaction(sig, NULL, &old_sa) == -1) { >>> - perror("fuse: cannot get old signal handler"); >>> + fuse_err("fuse: cannot get old signal handler: %s\n", >>> + strerror(errno)); >>> return -1; >>> } >>> >>> if (old_sa.sa_handler == (remove ? handler : SIG_DFL) && >>> sigaction(sig, &sa, NULL) == -1) { >>> - perror("fuse: cannot set signal handler"); >>> + fuse_err("fuse: cannot set signal handler: %s\n", >>> + strerror(errno)); >>> return -1; >>> } >>> return 0; >>> diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c >>> index 5b3174e4c74c..2ce0a9cf816e 100644 >>> --- a/contrib/virtiofsd/fuse_virtio.c >>> +++ b/contrib/virtiofsd/fuse_virtio.c >>> @@ -675,7 +675,7 @@ static void *fv_queue_thread(void *opaque) >>> fuse_info("%s: ppoll interrupted, going around\n", __func__); >>> continue; >>> } >>> - perror("fv_queue_thread ppoll"); >>> + fuse_err("fv_queue_thread ppoll: %s\n", strerror(errno)); >>> break; >>> } >>> assert(poll_res >= 1); >>> @@ -700,7 +700,7 @@ static void *fv_queue_thread(void *opaque) >>> >>> eventfd_t evalue; >>> if (eventfd_read(qi->kick_fd, &evalue)) { >>> - perror("Eventfd_read for queue"); >>> + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); >>> break; >>> } >>> >>> @@ -805,7 +805,7 @@ static void fv_queue_set_started(VuDev *dev, int qidx, bool started) >>> >>> /* Kill the thread */ >>> if (eventfd_write(ourqi->kill_fd, 1)) { >>> - perror("Eventfd_read for queue"); >>> + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); >>> } >>> ret = pthread_join(ourqi->thread, NULL); >>> if (ret) { >>> @@ -859,7 +859,7 @@ int virtio_loop(struct fuse_session *se) >>> fuse_info("%s: ppoll interrupted, going around\n", __func__); >>> continue; >>> } >>> - perror("virtio_loop ppoll"); >>> + fuse_err("virtio_loop ppoll: %s\n", strerror(errno)); >>> break; >>> } >>> assert(poll_res == 1); >>> @@ -913,18 +913,18 @@ static int fv_create_listen_socket(struct fuse_session *se) >>> >>> int listen_sock = socket(AF_UNIX, SOCK_STREAM, 0); >>> if (listen_sock == -1) { >>> - perror("vhost socket creation"); >>> + fuse_err("vhost socket creation: %s\n", strerror(errno)); >>> return -1; >>> } >>> un.sun_family = AF_UNIX; >>> >>> if (bind(listen_sock, (struct sockaddr *) &un, addr_len) == -1) { >>> - perror("vhost socket bind"); >>> + fuse_err("vhost socket bind: %s\n", strerror(errno)); >>> return -1; >>> } >>> >>> if (listen(listen_sock, 1) == -1) { >>> - perror("vhost socket listen"); >>> + fuse_err("vhost socket listen: %s\n", strerror(errno)); >>> return -1; >>> } >>> >>> @@ -949,7 +949,7 @@ int virtio_session_mount(struct fuse_session *se) >>> fuse_err("%s: Waiting for vhost-user socket connection...\n", __func__); >>> int data_sock = accept(se->vu_listen_fd, NULL, NULL); >>> if (data_sock == -1) { >>> - perror("vhost socket accept"); >>> + fuse_err("vhost socket accept: %s\n", strerror(errno)); >>> close(se->vu_listen_fd); >>> return -1; >>> } >>> diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c >>> index dc80100e8594..4c7145208028 100644 >>> --- a/contrib/virtiofsd/helper.c >>> +++ b/contrib/virtiofsd/helper.c >>> @@ -189,7 +189,7 @@ int fuse_daemonize(int foreground) >>> char completed; >>> >>> if (pipe(waiter)) { >>> - perror("fuse_daemonize: pipe"); >>> + fuse_err("fuse_daemonize: pipe: %s\n", strerror(errno)); >>> return -1; >>> } >>> >>> @@ -199,7 +199,7 @@ int fuse_daemonize(int foreground) >>> */ >>> switch(fork()) { >>> case -1: >>> - perror("fuse_daemonize: fork"); >>> + fuse_err("fuse_daemonize: fork: %s\n", strerror(errno)); >>> return -1; >>> case 0: >>> break; >>> @@ -209,7 +209,7 @@ int fuse_daemonize(int foreground) >>> } >>> >>> if (setsid() == -1) { >>> - perror("fuse_daemonize: setsid"); >>> + fuse_err("fuse_daemonize: setsid: %s\n", strerror(errno)); >>> return -1; >>> } >>> >>> >> >> _______________________________________________ >> Virtio-fs mailing list >> Virtio-fs@redhat.com >> https://www.redhat.com/mailman/listinfo/virtio-fs > . > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra 2019-08-09 8:25 ` [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra Eryu Guan 2019-08-09 9:40 ` piaojun @ 2019-08-16 16:52 ` Dr. David Alan Gilbert 1 sibling, 0 replies; 12+ messages in thread From: Dr. David Alan Gilbert @ 2019-08-16 16:52 UTC (permalink / raw) To: Eryu Guan; +Cc: virtio-fs * Eryu Guan (eguan@linux.alibaba.com) wrote: > Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> Thanks, merged. > --- > contrib/virtiofsd/fuse_lowlevel.c | 6 +++--- > contrib/virtiofsd/fuse_signals.c | 7 +++++-- > contrib/virtiofsd/fuse_virtio.c | 16 ++++++++-------- > contrib/virtiofsd/helper.c | 6 +++--- > 4 files changed, 19 insertions(+), 16 deletions(-) > > diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > index 7eec2680b6de..8ef800239f1e 100644 > --- a/contrib/virtiofsd/fuse_lowlevel.c > +++ b/contrib/virtiofsd/fuse_lowlevel.c > @@ -1901,15 +1901,15 @@ static void do_removemapping(fuse_req_t req, fuse_ino_t nodeid, > > arg = fuse_mbuf_iter_advance(iter, sizeof(*arg)); > if (!arg || arg->count <= 0) { > - fprintf(stderr, "do_removemapping: invalid arg %p\n", arg); > + fuse_err("do_removemapping: invalid arg %p\n", arg); > fuse_reply_err(req, EINVAL); > return; > } > > one = fuse_mbuf_iter_advance(iter, arg->count * sizeof(*one)); > if (!one) { > - fprintf(stderr, "do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", > - arg->count, sizeof(*one), iter->size, iter->pos); > + fuse_err("do_removemapping: invalid in, expected %d * %ld, has %ld - %ld\n", > + arg->count, sizeof(*one), iter->size, iter->pos); > fuse_reply_err(req, EINVAL); > return; > } > diff --git a/contrib/virtiofsd/fuse_signals.c b/contrib/virtiofsd/fuse_signals.c > index aa3bdba7daaf..9d34f6b04025 100644 > --- a/contrib/virtiofsd/fuse_signals.c > +++ b/contrib/virtiofsd/fuse_signals.c > @@ -12,6 +12,7 @@ > #include "fuse_log.h" > #include "fuse_lowlevel.h" > > +#include <errno.h> > #include <stdio.h> > #include <string.h> > #include <signal.h> > @@ -47,13 +48,15 @@ static int set_one_signal_handler(int sig, void (*handler)(int), int remove) > sa.sa_flags = 0; > > if (sigaction(sig, NULL, &old_sa) == -1) { > - perror("fuse: cannot get old signal handler"); > + fuse_err("fuse: cannot get old signal handler: %s\n", > + strerror(errno)); > return -1; > } > > if (old_sa.sa_handler == (remove ? handler : SIG_DFL) && > sigaction(sig, &sa, NULL) == -1) { > - perror("fuse: cannot set signal handler"); > + fuse_err("fuse: cannot set signal handler: %s\n", > + strerror(errno)); > return -1; > } > return 0; > diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > index 5b3174e4c74c..2ce0a9cf816e 100644 > --- a/contrib/virtiofsd/fuse_virtio.c > +++ b/contrib/virtiofsd/fuse_virtio.c > @@ -675,7 +675,7 @@ static void *fv_queue_thread(void *opaque) > fuse_info("%s: ppoll interrupted, going around\n", __func__); > continue; > } > - perror("fv_queue_thread ppoll"); > + fuse_err("fv_queue_thread ppoll: %s\n", strerror(errno)); > break; > } > assert(poll_res >= 1); > @@ -700,7 +700,7 @@ static void *fv_queue_thread(void *opaque) > > eventfd_t evalue; > if (eventfd_read(qi->kick_fd, &evalue)) { > - perror("Eventfd_read for queue"); > + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); > break; > } > > @@ -805,7 +805,7 @@ static void fv_queue_set_started(VuDev *dev, int qidx, bool started) > > /* Kill the thread */ > if (eventfd_write(ourqi->kill_fd, 1)) { > - perror("Eventfd_read for queue"); > + fuse_err("Eventfd_read for queue: %s\n", strerror(errno)); > } > ret = pthread_join(ourqi->thread, NULL); > if (ret) { > @@ -859,7 +859,7 @@ int virtio_loop(struct fuse_session *se) > fuse_info("%s: ppoll interrupted, going around\n", __func__); > continue; > } > - perror("virtio_loop ppoll"); > + fuse_err("virtio_loop ppoll: %s\n", strerror(errno)); > break; > } > assert(poll_res == 1); > @@ -913,18 +913,18 @@ static int fv_create_listen_socket(struct fuse_session *se) > > int listen_sock = socket(AF_UNIX, SOCK_STREAM, 0); > if (listen_sock == -1) { > - perror("vhost socket creation"); > + fuse_err("vhost socket creation: %s\n", strerror(errno)); > return -1; > } > un.sun_family = AF_UNIX; > > if (bind(listen_sock, (struct sockaddr *) &un, addr_len) == -1) { > - perror("vhost socket bind"); > + fuse_err("vhost socket bind: %s\n", strerror(errno)); > return -1; > } > > if (listen(listen_sock, 1) == -1) { > - perror("vhost socket listen"); > + fuse_err("vhost socket listen: %s\n", strerror(errno)); > return -1; > } > > @@ -949,7 +949,7 @@ int virtio_session_mount(struct fuse_session *se) > fuse_err("%s: Waiting for vhost-user socket connection...\n", __func__); > int data_sock = accept(se->vu_listen_fd, NULL, NULL); > if (data_sock == -1) { > - perror("vhost socket accept"); > + fuse_err("vhost socket accept: %s\n", strerror(errno)); > close(se->vu_listen_fd); > return -1; > } > diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > index dc80100e8594..4c7145208028 100644 > --- a/contrib/virtiofsd/helper.c > +++ b/contrib/virtiofsd/helper.c > @@ -189,7 +189,7 @@ int fuse_daemonize(int foreground) > char completed; > > if (pipe(waiter)) { > - perror("fuse_daemonize: pipe"); > + fuse_err("fuse_daemonize: pipe: %s\n", strerror(errno)); > return -1; > } > > @@ -199,7 +199,7 @@ int fuse_daemonize(int foreground) > */ > switch(fork()) { > case -1: > - perror("fuse_daemonize: fork"); > + fuse_err("fuse_daemonize: fork: %s\n", strerror(errno)); > return -1; > case 0: > break; > @@ -209,7 +209,7 @@ int fuse_daemonize(int foreground) > } > > if (setsid() == -1) { > - perror("fuse_daemonize: setsid"); > + fuse_err("fuse_daemonize: setsid: %s\n", strerror(errno)); > return -1; > } > > -- > 2.14.4.44.g2045bb6 > > _______________________________________________ > Virtio-fs mailing list > Virtio-fs@redhat.com > https://www.redhat.com/mailman/listinfo/virtio-fs -- Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough 2019-08-09 8:25 [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough Eryu Guan 2019-08-09 8:25 ` [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra Eryu Guan @ 2019-08-09 9:34 ` piaojun 2019-08-11 13:20 ` Eryu Guan 1 sibling, 1 reply; 12+ messages in thread From: piaojun @ 2019-08-09 9:34 UTC (permalink / raw) To: Eryu Guan, virtio-fs Hi Eryu, A very big patch, and I prefer spliting into several ones. On 2019/8/9 16:25, Eryu Guan wrote: > Introduce "-o log_level=" command line option to specify current log > level (priority), valid values are "debug info warn err", e.g. > > ./virtiofsd -o log_level=debug ... > > So only log priority higher than "debug" will be printed to > stderr/syslog. And the default level is info. > > The "-o debug"/"-d" options are kept, and imply debug log level. I wonder if this will make user confused when there are two options for debug. > > Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> > --- > contrib/virtiofsd/fuse_log.c | 9 ++- > contrib/virtiofsd/fuse_log.h | 4 + > contrib/virtiofsd/fuse_lowlevel.c | 77 +++++++----------- > contrib/virtiofsd/fuse_lowlevel.h | 1 + > contrib/virtiofsd/fuse_virtio.c | 104 ++++++++++--------------- > contrib/virtiofsd/helper.c | 10 ++- > contrib/virtiofsd/passthrough_ll.c | 156 +++++++++++++++---------------------- > 7 files changed, 153 insertions(+), 208 deletions(-) > > diff --git a/contrib/virtiofsd/fuse_log.c b/contrib/virtiofsd/fuse_log.c > index 4eb25328721e..d54b64099a2b 100644 > --- a/contrib/virtiofsd/fuse_log.c > +++ b/contrib/virtiofsd/fuse_log.c > @@ -9,10 +9,10 @@ > #include <stdbool.h> > #include <stdio.h> > #include <stdarg.h> > -#include <syslog.h> > #include "fuse_log.h" > > static bool use_syslog; > +int current_log_level = LOG_INFO; Shall we make it static var which won't populate other files? Jun > > void fuse_log_enable_syslog(void) > { > @@ -24,10 +24,13 @@ void fuse_log_enable_syslog(void) > openlog("virtiofsd", LOG_PID, LOG_DAEMON); > } > > -static void fuse_vlog(int priority, const char *fmt, va_list ap) > +static void fuse_vlog(int target_level, const char *fmt, va_list ap) > { > + if (current_log_level < target_level) > + return; > + > if (use_syslog) { > - vsyslog(priority, fmt, ap); > + vsyslog(target_level, fmt, ap); > } else { > vfprintf(stderr, fmt, ap); > } > diff --git a/contrib/virtiofsd/fuse_log.h b/contrib/virtiofsd/fuse_log.h > index 3c22928d2b1d..c4dfc921b6d8 100644 > --- a/contrib/virtiofsd/fuse_log.h > +++ b/contrib/virtiofsd/fuse_log.h > @@ -9,8 +9,12 @@ > #ifndef FUSE_LOG_H > #define FUSE_LOG_H > > +#include <syslog.h> > #include "qemu/compiler.h" > > +/* Current log level */ > +extern int current_log_level; > + > void fuse_log_enable_syslog(void); > void fuse_err(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > void fuse_warning(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > index 8d3f141d23cf..7eec2680b6de 100644 > --- a/contrib/virtiofsd/fuse_lowlevel.c > +++ b/contrib/virtiofsd/fuse_lowlevel.c > @@ -155,19 +155,17 @@ static int fuse_send_msg(struct fuse_session *se, struct fuse_chan *ch, > struct fuse_out_header *out = iov[0].iov_base; > > out->len = iov_length(iov, count); > - if (se->debug) { > - if (out->unique == 0) { > - fuse_debug("NOTIFY: code=%d length=%u\n", > - out->error, out->len); > - } else if (out->error) { > - fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > - (unsigned long long) out->unique, > - out->error, strerror(-out->error), > - out->len); > - } else { > - fuse_debug(" unique: %llu, success, outsize: %i\n", > - (unsigned long long) out->unique, out->len); > - } > + if (out->unique == 0) { > + fuse_debug("NOTIFY: code=%d length=%u\n", > + out->error, out->len); > + } else if (out->error) { > + fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > + (unsigned long long) out->unique, > + out->error, strerror(-out->error), > + out->len); > + } else { > + fuse_debug(" unique: %llu, success, outsize: %i\n", > + (unsigned long long) out->unique, out->len); > } > > if (fuse_lowlevel_is_virtio(se)) { > @@ -1668,9 +1666,7 @@ static void do_interrupt(fuse_req_t req, fuse_ino_t nodeid, > return; > } > > - if (se->debug) > - fuse_debug("INTERRUPT: %llu\n", > - (unsigned long long) arg->unique); > + fuse_debug("INTERRUPT: %llu\n", (unsigned long long) arg->unique); > > req->u.i.unique = arg->unique; > > @@ -1952,13 +1948,10 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > } > } > > - if (se->debug) { > - fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > - if (arg->major == 7 && arg->minor >= 6) { > - fuse_debug("flags=0x%08x\n", arg->flags); > - fuse_debug("max_readahead=0x%08x\n", > - arg->max_readahead); > - } > + fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > + if (arg->major == 7 && arg->minor >= 6) { > + fuse_debug("flags=0x%08x\n", arg->flags); > + fuse_debug("max_readahead=0x%08x\n", arg->max_readahead); > } > se->conn.proto_major = arg->major; > se->conn.proto_minor = arg->minor; > @@ -2135,21 +2128,14 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > outarg.map_alignment = sysconf(_SC_PAGE_SIZE); > } > > - if (se->debug) { > - fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > - fuse_debug(" flags=0x%08x\n", outarg.flags); > - fuse_debug(" max_readahead=0x%08x\n", > - outarg.max_readahead); > - fuse_debug(" max_write=0x%08x\n", outarg.max_write); > - fuse_debug(" max_background=%i\n", > - outarg.max_background); > - fuse_debug(" congestion_threshold=%i\n", > - outarg.congestion_threshold); > - fuse_debug(" time_gran=%u\n", > - outarg.time_gran); > - fuse_debug(" map_alignment=%u\n", > - outarg.map_alignment); > - } > + fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > + fuse_debug(" flags=0x%08x\n", outarg.flags); > + fuse_debug(" max_readahead=0x%08x\n", outarg.max_readahead); > + fuse_debug(" max_write=0x%08x\n", outarg.max_write); > + fuse_debug(" max_background=%i\n", outarg.max_background); > + fuse_debug(" congestion_threshold=%i\n", outarg.congestion_threshold); > + fuse_debug(" time_gran=%u\n", outarg.time_gran); > + fuse_debug(" map_alignment=%u\n", outarg.map_alignment); > if (arg->minor < 5) > outargsize = FUSE_COMPAT_INIT_OUT_SIZE; > else if (arg->minor < 23) > @@ -2440,13 +2426,11 @@ void fuse_session_process_buf_int(struct fuse_session *se, > in = fuse_mbuf_iter_advance(&iter, sizeof(*in)); > assert(in); /* caller guarantees the input buffer is large enough */ > > - if (se->debug) { > - fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > - (unsigned long long) in->unique, > - opname((enum fuse_opcode) in->opcode), in->opcode, > - (unsigned long long) in->nodeid, buf->size, > - in->pid); > - } > + fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > + (unsigned long long) in->unique, > + opname((enum fuse_opcode) in->opcode), in->opcode, > + (unsigned long long) in->nodeid, buf->size, > + in->pid); > > req = fuse_ll_alloc_req(se); > if (req == NULL) { > @@ -2493,8 +2477,7 @@ void fuse_session_process_buf_int(struct fuse_session *se, > // TODO: This is after a hard reboot typically, we need to do > // a destroy, but we can't reply to this request yet so > // we can't use do_destroy > - if (se->debug) > - fuse_debug("%s: reinit\n", __func__); > + fuse_debug("%s: reinit\n", __func__); > se->got_destroy = 1; > se->got_init = 0; > if (se->op.destroy) > diff --git a/contrib/virtiofsd/fuse_lowlevel.h b/contrib/virtiofsd/fuse_lowlevel.h > index e761d8d0e5ec..b441d3dfedeb 100644 > --- a/contrib/virtiofsd/fuse_lowlevel.h > +++ b/contrib/virtiofsd/fuse_lowlevel.h > @@ -1798,6 +1798,7 @@ struct fuse_cmdline_opts { > int show_help; > int clone_fd; > int syslog; > + int log_level; > unsigned int max_idle_threads; > }; > > diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > index 72ddf703c9d4..5b3174e4c74c 100644 > --- a/contrib/virtiofsd/fuse_virtio.c > +++ b/contrib/virtiofsd/fuse_virtio.c > @@ -223,9 +223,8 @@ int virtio_send_msg(struct fuse_session *se, struct fuse_chan *ch, > unsigned int in_num = elem->in_num; > struct iovec *in_sg = elem->in_sg; > size_t in_len = iov_length(in_sg, in_num); > - if (se->debug) > - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > - __func__, elem->index, in_num, in_len); > + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > + __func__, elem->index, in_num, in_len); > > /* The elem should have room for a 'fuse_out_header' (out from fuse) > * plus the data based on the len in the header. > @@ -286,9 +285,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > out->len = tosend_len; > > - if (se->debug) > - fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > - __func__, count, len, iov_len); > + fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > + __func__, count, len, iov_len); > > /* unique == 0 is notification which we don't support */ > assert (out->unique); > @@ -301,9 +299,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > struct iovec *in_sg = elem->in_sg; > size_t in_len = iov_length(in_sg, in_num); > size_t in_len_writeable = iov_length(in_sg, in_num - bad_in_num); > - if (se->debug) > - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > - __func__, elem->index, in_num, in_len); > + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > + __func__, elem->index, in_num, in_len); > > /* The elem should have room for a 'fuse_out_header' (out from fuse) > * plus the data based on the len in the header. > @@ -356,23 +353,19 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > for (i = 0, in_sg_left = 0; i < in_sg_cpy_count; i++) { > in_sg_left += in_sg_ptr[i].iov_len; > } > - if (se->debug) > - fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > - __func__, skip_size, in_sg_cpy_count, > - in_sg_left); > + fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > + __func__, skip_size, in_sg_cpy_count, in_sg_left); > ret = preadv(buf->buf[0].fd, in_sg_ptr, in_sg_cpy_count, buf->buf[0].pos); > > - if (se->debug) > - fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > - __func__, ret, strerror(errno), len); > + fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > + __func__, ret, strerror(errno), len); > if (ret == -1) { > ret = errno; > free(in_sg_cpy); > goto err; > } > if (ret < len && ret) { > - if (se->debug) > - fuse_debug("%s: ret < len\n", __func__); > + fuse_debug("%s: ret < len\n", __func__); > /* Skip over this much next time around */ > skip_size = ret; > buf->buf[0].pos += ret; > @@ -383,14 +376,12 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > } > if (!ret) { > /* EOF case? */ > - if (se->debug) > - fuse_debug("%s: !ret in_sg_left=%zd\n", > - __func__, in_sg_left); > + fuse_debug("%s: !ret in_sg_left=%zd\n", > + __func__, in_sg_left); > break; > } > if (ret != len) { > - if (se->debug) > - fuse_debug("%s: ret!=len\n", __func__); > + fuse_debug("%s: ret!=len\n", __func__); > ret = EIO; > free(in_sg_cpy); > goto err; > @@ -410,11 +401,10 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > msg.len[0] = len; > } > int64_t req_res =fuse_virtio_io(se, &msg, buf->buf[0].fd); > - if (se->debug) > - fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > - __func__, len, bad_in_num, > - buf->buf[0].pos, > - in_sg_ptr[0].iov_base, req_res); > + fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > + __func__, len, bad_in_num, > + buf->buf[0].pos, > + in_sg_ptr[0].iov_base, req_res); > if (req_res > 0) { > len -= msg.len[0]; > buf->buf[0].pos += msg.len[0]; > @@ -488,11 +478,10 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > struct iovec *out_sg = elem->out_sg; > size_t out_len = iov_length(out_sg, out_num); > size_t out_len_readable = iov_length(out_sg, out_num_readable); > - if (se->debug) > - fuse_debug("%s: elem %d: with %d out desc of length %zd" > - " bad_in_num=%u bad_out_num=%u\n", > - __func__, elem->index, out_num, > - out_len, req->bad_in_num, req->bad_out_num); > + fuse_debug("%s: elem %d: with %d out desc of length %zd" > + " bad_in_num=%u bad_out_num=%u\n", > + __func__, elem->index, out_num, > + out_len, req->bad_in_num, req->bad_out_num); > > /* The elem should contain a 'fuse_in_header' (in to fuse) > * plus the data based on the len in the header. > @@ -555,11 +544,9 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > ((struct fuse_in_header *)fbuf.mem)->opcode == > FUSE_READ && > out_sg[1].iov_len == sizeof(struct fuse_read_in)) { > - if (se->debug) { > - fuse_debug("Unmappable read case " > - "in_num=%d bad_in_num=%d\n", > - elem->in_num, req->bad_in_num); > - } > + fuse_debug("Unmappable read case " > + "in_num=%d bad_in_num=%d\n", > + elem->in_num, req->bad_in_num); > handled_unmappable = true; > } > > @@ -581,8 +568,7 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > // data, we can just do it straight out of guest memory > // but we must sitll copy the headers in case the guest > // was nasty and changed them while we were using them. > - if (se->debug) > - fuse_debug("%s: Write special case\n", __func__); > + fuse_debug("%s: Write special case\n", __func__); > > // copy the fuse_write_in header afte rthe fuse_in_header > fbuf.mem += out_sg->iov_len; > @@ -636,10 +622,8 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > if (!req->reply_sent) { > struct VuVirtq *q = vu_get_queue(dev, qi->qidx); > > - if (se->debug) { > - fuse_debug("%s: elem %d no reply sent\n", > - __func__, elem->index); > - } > + fuse_debug("%s: elem %d no reply sent\n", > + __func__, elem->index); > > pthread_rwlock_rdlock(&qi->virtio_dev->vu_dispatch_rwlock); > pthread_mutex_lock(&qi->vq_lock); > @@ -683,8 +667,7 @@ static void *fv_queue_thread(void *opaque) > pf[1].events = POLLIN; > pf[1].revents = 0; > > - if (qi->virtio_dev->se->debug) > - fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > + fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > int poll_res = ppoll(pf, 2, NULL, NULL); > > if (poll_res == -1) { > @@ -712,9 +695,8 @@ static void *fv_queue_thread(void *opaque) > break; > } > assert(pf[0].revents & POLLIN); > - if (qi->virtio_dev->se->debug) > - fuse_debug("%s: Got queue event on Queue %d\n", > - __func__, qi->qidx); > + fuse_debug("%s: Got queue event on Queue %d\n", > + __func__, qi->qidx); > > eventfd_t evalue; > if (eventfd_read(qi->kick_fd, &evalue)) { > @@ -728,15 +710,13 @@ static void *fv_queue_thread(void *opaque) > > pthread_mutex_lock(&qi->vq_lock); > > - if (se->debug) { > - /* out is from guest, in is too guest */ > - unsigned int in_bytes, out_bytes; > - vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > + /* out is from guest, in is too guest */ > + unsigned int in_bytes, out_bytes; > + vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > > - fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > - __func__, qi->qidx, (size_t)evalue, in_bytes, > - out_bytes); > - } > + fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > + __func__, qi->qidx, (size_t)evalue, in_bytes, > + out_bytes); > > while (1) { > unsigned int bad_in_num = 0, bad_out_num = 0; > @@ -871,8 +851,7 @@ int virtio_loop(struct fuse_session *se) > pf[0].events = POLLIN; > pf[0].revents = 0; > > - if (se->debug) > - fuse_debug("%s: Waiting for VU event\n", __func__); > + fuse_debug("%s: Waiting for VU event\n", __func__); > int poll_res = ppoll(pf, 1, NULL, NULL); > > if (poll_res == -1) { > @@ -890,8 +869,7 @@ int virtio_loop(struct fuse_session *se) > break; > } > assert(pf[0].revents & POLLIN); > - if (se->debug) > - fuse_debug("%s: Got VU event\n", __func__); > + fuse_debug("%s: Got VU event\n", __func__); > > /* Mutual exclusion with fv_queue_thread() */ > ret = pthread_rwlock_wrlock(&se->virtio_dev->vu_dispatch_rwlock); > @@ -1058,9 +1036,7 @@ ssize_t fuse_virtio_write(fuse_req_t req, > msg.flags[0] = VHOST_USER_FS_FLAG_MAP_W; > > int64_t result = fuse_virtio_io(req->se, &msg, dst->fd); > - if (req->se->debug) { > - fuse_debug("%s: result=%ld\n", __func__, result); > - } > + fuse_debug("%s: result=%ld\n", __func__, result); > return result; > } > > diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > index 5eae1f530aae..dc80100e8594 100644 > --- a/contrib/virtiofsd/helper.c > +++ b/contrib/virtiofsd/helper.c > @@ -27,6 +27,8 @@ > > #define FUSE_HELPER_OPT(t, p) \ > { t, offsetof(struct fuse_cmdline_opts, p), 1 } > +#define FUSE_HELPER_OPT_VALUE(t, p, v) \ > + { t, offsetof(struct fuse_cmdline_opts, p), v } > > static const struct fuse_opt fuse_helper_opts[] = { > FUSE_HELPER_OPT("-h", show_help), > @@ -50,6 +52,10 @@ static const struct fuse_opt fuse_helper_opts[] = { > FUSE_HELPER_OPT("clone_fd", clone_fd), > FUSE_HELPER_OPT("max_idle_threads=%u", max_idle_threads), > FUSE_HELPER_OPT("--syslog", syslog), > + FUSE_HELPER_OPT_VALUE("log_level=debug", log_level, LOG_DEBUG), > + FUSE_HELPER_OPT_VALUE("log_level=info", log_level, LOG_INFO), > + FUSE_HELPER_OPT_VALUE("log_level=warn", log_level, LOG_WARNING), > + FUSE_HELPER_OPT_VALUE("log_level=err", log_level, LOG_ERR), > FUSE_OPT_END > }; > > @@ -137,7 +143,9 @@ void fuse_cmdline_help(void) > " -o clone_fd use separate fuse device fd for each thread\n" > " (may improve performance)\n" > " -o max_idle_threads the maximum number of idle worker threads\n" > - " allowed (default: 10)\n"); > + " allowed (default: 10)\n" > + " -o log_level=<level> log level, default to \"info\"\n" > + " level could be one of \"debug, info, warn, err\"\n"); > } > > static int fuse_helper_opt_proc(void *data, const char *arg, int key, > diff --git a/contrib/virtiofsd/passthrough_ll.c b/contrib/virtiofsd/passthrough_ll.c > index 321bbb20be65..583e9685161f 100644 > --- a/contrib/virtiofsd/passthrough_ll.c > +++ b/contrib/virtiofsd/passthrough_ll.c > @@ -36,6 +36,7 @@ > > #include "fuse_virtio.h" > #include "fuse_lowlevel.h" > +#include "fuse_log.h" > #include <unistd.h> > #include <stdlib.h> > #include <stdio.h> > @@ -421,11 +422,6 @@ static int lo_fd(fuse_req_t req, fuse_ino_t ino) > return fd; > } > > -static bool lo_debug(fuse_req_t req) > -{ > - return lo_data(req)->debug != 0; > -} > - > static void lo_init(void *userdata, > struct fuse_conn_info *conn) > { > @@ -436,18 +432,15 @@ static void lo_init(void *userdata, > > if (lo->writeback && > conn->capable & FUSE_CAP_WRITEBACK_CACHE) { > - if (lo->debug) > - fuse_debug("lo_init: activating writeback\n"); > + fuse_debug("lo_init: activating writeback\n"); > conn->want |= FUSE_CAP_WRITEBACK_CACHE; > } > if (conn->capable & FUSE_CAP_FLOCK_LOCKS) { > if (lo->flock) { > - if (lo->debug) > - fuse_debug("lo_init: activating flock locks\n"); > + fuse_debug("lo_init: activating flock locks\n"); > conn->want |= FUSE_CAP_FLOCK_LOCKS; > } else { > - if (lo->debug) > - fuse_debug("lo_init: disabling flock locks\n"); > + fuse_debug("lo_init: disabling flock locks\n"); > conn->want &= ~FUSE_CAP_FLOCK_LOCKS; > } > } > @@ -455,20 +448,17 @@ static void lo_init(void *userdata, > > if (conn->capable & FUSE_CAP_POSIX_LOCKS) { > if (lo->posix_lock) { > - if (lo->debug) > - fuse_debug("lo_init: activating posix locks\n"); > + fuse_debug("lo_init: activating posix locks\n"); > conn->want |= FUSE_CAP_POSIX_LOCKS; > } else { > - if (lo->debug) > - fuse_debug("lo_init: disabling posix locks\n"); > + fuse_debug("lo_init: disabling posix locks\n"); > conn->want &= ~FUSE_CAP_POSIX_LOCKS; > } > } > > if ((lo->cache == CACHE_NONE && !lo->readdirplus_set) || > lo->readdirplus_clear || lo->shared) { > - if (lo->debug) > - fuse_debug("lo_init: disabling readdirplus\n"); > + fuse_debug("lo_init: disabling readdirplus\n"); > conn->want &= ~FUSE_CAP_READDIRPLUS; > } > } > @@ -909,12 +899,11 @@ static int lo_do_lookup(fuse_req_t req, fuse_ino_t parent, const char *name, > lo_inode_put(lo, &inode); > lo_inode_put(lo, &dir); > > - if (lo_debug(req)) > - fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > - (unsigned long long) parent, name, > - (unsigned long long) e->ino, > - (unsigned long long) e->version_offset, > - (unsigned long long) e->initial_version); > + fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > + (unsigned long long) parent, name, > + (unsigned long long) e->ino, > + (unsigned long long) e->version_offset, > + (unsigned long long) e->initial_version); > > return 0; > > @@ -932,9 +921,7 @@ static void lo_lookup(fuse_req_t req, fuse_ino_t parent, const char *name) > struct fuse_entry_param e; > int err; > > - if (lo_debug(req)) > - fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", > - parent, name); > + fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", parent, name); > > /* Don't use is_safe_path_component(), allow "." and ".." for NFS export > * support. > @@ -1040,10 +1027,9 @@ static void lo_mknod_symlink(fuse_req_t req, fuse_ino_t parent, > if (saverr) > goto out; > > - if (lo_debug(req)) > - fuse_debug(" %lli/%s -> %lli\n", > - (unsigned long long) parent, name, > - (unsigned long long) e.ino); > + fuse_debug(" %lli/%s -> %lli\n", > + (unsigned long long) parent, name, > + (unsigned long long) e.ino); > > fuse_reply_entry(req, &e, lo->shared); > lo_inode_put(lo, &dir); > @@ -1149,10 +1135,9 @@ static void lo_link(fuse_req_t req, fuse_ino_t ino, fuse_ino_t parent, > update_version(lo, inode); > update_version(lo, parent_inode); > > - if (lo_debug(req)) > - fuse_debug(" %lli/%s -> %lli\n", > - (unsigned long long) parent, name, > - (unsigned long long) e.ino); > + fuse_debug(" %lli/%s -> %lli\n", > + (unsigned long long) parent, name, > + (unsigned long long) e.ino); > > fuse_reply_entry(req, &e, lo->shared); > lo_inode_put(lo, &parent_inode); > @@ -1355,12 +1340,10 @@ static void lo_forget_one(fuse_req_t req, fuse_ino_t ino, uint64_t nlookup) > if (!inode) > return; > > - if (lo_debug(req)) { > - fuse_debug(" forget %lli %lli -%lli\n", > - (unsigned long long) ino, > - (unsigned long long) inode->nlookup, > - (unsigned long long) nlookup); > - } > + fuse_debug(" forget %lli %lli -%lli\n", > + (unsigned long long) ino, > + (unsigned long long) inode->nlookup, > + (unsigned long long) nlookup); > > unref_inode(lo, inode, nlookup); > lo_inode_put(lo, &inode); > @@ -1642,9 +1625,7 @@ static void lo_create(fuse_req_t req, fuse_ino_t parent, const char *name, > int err; > struct lo_cred old = {}; > > - if (lo_debug(req)) > - fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", > - parent, name); > + fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", parent, name); > > if (!is_safe_path_component(name)) { > fuse_reply_err(req, EINVAL); > @@ -1744,11 +1725,10 @@ static void lo_getlk(fuse_req_t req, fuse_ino_t ino, > struct lo_inode_plock *plock; > int ret, saverr = 0; > > - if (lo_debug(req)) > - fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > - " owner=0x%lx, l_type=%d l_start=0x%lx" > - " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > - lock->l_type, lock->l_start, lock->l_len); > + fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > + " owner=0x%lx, l_type=%d l_start=0x%lx" > + " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > + lock->l_type, lock->l_start, lock->l_len); > > inode = lo_inode(req, ino); > if (!inode) { > @@ -1786,12 +1766,11 @@ static void lo_setlk(fuse_req_t req, fuse_ino_t ino, > struct lo_inode_plock *plock; > int ret, saverr = 0; > > - if (lo_debug(req)) > - fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > - " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > - " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > - lock->l_type, lock->l_pid, fi->lock_owner, sleep, > - lock->l_whence, lock->l_start, lock->l_len); > + fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > + " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > + " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > + lock->l_type, lock->l_pid, fi->lock_owner, sleep, > + lock->l_whence, lock->l_start, lock->l_len); > > if (sleep) { > fuse_reply_err(req, EOPNOTSUPP); > @@ -1860,9 +1839,7 @@ static void lo_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info *fi) > char buf[64]; > struct lo_data *lo = lo_data(req); > > - if (lo_debug(req)) > - fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", > - ino, fi->flags); > + fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", ino, fi->flags); > > /* With writeback cache, kernel may send read requests even > when userspace opened write-only */ > @@ -1965,9 +1942,7 @@ static void lo_fsync(fuse_req_t req, fuse_ino_t ino, int datasync, > int fd; > char *buf; > > - if (lo_debug(req)) > - fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, > - (void *)fi); > + fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, (void *)fi); > > if (!fi) { > res = asprintf(&buf, "%i", lo_fd(req, ino)); > @@ -1995,9 +1970,8 @@ static void lo_read(fuse_req_t req, fuse_ino_t ino, size_t size, > { > struct fuse_bufvec buf = FUSE_BUFVEC_INIT(size); > > - if (lo_debug(req)) > - fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > - "off=%lu)\n", ino, size, (unsigned long) offset); > + fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > + "off=%lu)\n", ino, size, (unsigned long) offset); > > buf.buf[0].flags = FUSE_BUF_IS_FD | FUSE_BUF_FD_SEEK; > buf.buf[0].fd = lo_fi_fd(req, fi); > @@ -2019,9 +1993,8 @@ static void lo_write_buf(fuse_req_t req, fuse_ino_t ino, > out_buf.buf[0].fd = lo_fi_fd(req, fi); > out_buf.buf[0].pos = off; > > - if (lo_debug(req)) > - fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > - ino, out_buf.buf[0].size, (unsigned long) off); > + fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > + ino, out_buf.buf[0].size, (unsigned long) off); > > res = fuse_buf_copy(req, &out_buf, in_buf, 0); > if(res < 0) { > @@ -2105,10 +2078,8 @@ static void lo_getxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > if (!lo_data(req)->xattr) > goto out; > > - if (lo_debug(req)) { > - fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > - ino, name, size); > - } > + fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > + ino, name, size); > > if (inode->is_symlink) { > /* Sorry, no race free way to getxattr on symlink. */ > @@ -2180,10 +2151,7 @@ static void lo_listxattr(fuse_req_t req, fuse_ino_t ino, size_t size) > if (!lo_data(req)->xattr) > goto out; > > - if (lo_debug(req)) { > - fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", > - ino, size); > - } > + fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", ino, size); > > if (inode->is_symlink) { > /* Sorry, no race free way to listxattr on symlink. */ > @@ -2255,10 +2223,8 @@ static void lo_setxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > if (!lo_data(req)->xattr) > goto out; > > - if (lo_debug(req)) { > - fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > - ino, name, value, size); > - } > + fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > + ino, name, value, size); > > if (inode->is_symlink) { > /* Sorry, no race free way to removexattr on symlink. */ > @@ -2306,10 +2272,7 @@ static void lo_removexattr(fuse_req_t req, fuse_ino_t ino, const char *name) > if (!lo_data(req)->xattr) > goto out; > > - if (lo_debug(req)) { > - fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", > - ino, name); > - } > + fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", ino, name); > > if (inode->is_symlink) { > /* Sorry, no race free way to setxattr on symlink. */ > @@ -2351,12 +2314,11 @@ static void lo_copy_file_range(fuse_req_t req, fuse_ino_t ino_in, off_t off_in, > in_fd = lo_fi_fd(req, fi_in); > out_fd = lo_fi_fd(req, fi_out); > > - if (lo_debug(req)) > - fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > - "off=%lu, ino=%" PRIu64 "/fd=%d, " > - "off=%lu, size=%zd, flags=0x%x)\n", > - ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > - flags); > + fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > + "off=%lu, ino=%" PRIu64 "/fd=%d, " > + "off=%lu, size=%zd, flags=0x%x)\n", > + ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > + flags); > > res = copy_file_range(in_fd, &off_in, out_fd, &off_out, len, flags); > if (res < 0) > @@ -2377,11 +2339,10 @@ static void lo_setupmapping(fuse_req_t req, fuse_ino_t ino, uint64_t foffset, > char *buf; > bool writable = flags & O_RDWR; > > - if (lo_debug(req)) > - fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > - " foffset=%" PRIu64 ", len=%" PRIu64 > - ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > - (void *)fi, foffset, len, moffset, flags); > + fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > + " foffset=%" PRIu64 ", len=%" PRIu64 > + ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > + (void *)fi, foffset, len, moffset, flags); > > vhu_flags = VHOST_USER_FS_FLAG_MAP_R; > if (writable) > @@ -2878,7 +2839,16 @@ int main(int argc, char *argv[]) > if (fuse_opt_parse(&args, &lo, lo_opts, NULL)== -1) > goto err_out1; > > + /* > + * log_level is 0 if not configured via cmd options (0 is LOG_EMERG, > + * and we don't use this log level). > + */ > + if (opts.log_level != 0) > + current_log_level = opts.log_level; > lo.debug = opts.debug; > + if (lo.debug) > + current_log_level = LOG_DEBUG; > + > if (lo.source) { > struct stat stat; > int res; > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough 2019-08-09 9:34 ` [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough piaojun @ 2019-08-11 13:20 ` Eryu Guan 2019-08-11 14:32 ` piaojun 0 siblings, 1 reply; 12+ messages in thread From: Eryu Guan @ 2019-08-11 13:20 UTC (permalink / raw) To: piaojun; +Cc: virtio-fs On Fri, Aug 09, 2019 at 05:34:06PM +0800, piaojun wrote: > Hi Eryu, > > A very big patch, and I prefer spliting into several ones. Most of the changes are replacing if (lo->debug) fuse_debug(...); to fuse_debug(...); But yeah, it's fine to split, one patches introduce current_log_level related code, one does the replacements. > > On 2019/8/9 16:25, Eryu Guan wrote: > > Introduce "-o log_level=" command line option to specify current log > > level (priority), valid values are "debug info warn err", e.g. > > > > ./virtiofsd -o log_level=debug ... > > > > So only log priority higher than "debug" will be printed to > > stderr/syslog. And the default level is info. > > > > The "-o debug"/"-d" options are kept, and imply debug log level. > > I wonder if this will make user confused when there are two options for > debug. Forgot to mention, one reason to keep "-o debug/-d" options is try not to break existing users, e.g. kata-runtime. But I have no strong preference on this. > > > > > Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> > > --- > > contrib/virtiofsd/fuse_log.c | 9 ++- > > contrib/virtiofsd/fuse_log.h | 4 + > > contrib/virtiofsd/fuse_lowlevel.c | 77 +++++++----------- > > contrib/virtiofsd/fuse_lowlevel.h | 1 + > > contrib/virtiofsd/fuse_virtio.c | 104 ++++++++++--------------- > > contrib/virtiofsd/helper.c | 10 ++- > > contrib/virtiofsd/passthrough_ll.c | 156 +++++++++++++++---------------------- > > 7 files changed, 153 insertions(+), 208 deletions(-) > > > > diff --git a/contrib/virtiofsd/fuse_log.c b/contrib/virtiofsd/fuse_log.c > > index 4eb25328721e..d54b64099a2b 100644 > > --- a/contrib/virtiofsd/fuse_log.c > > +++ b/contrib/virtiofsd/fuse_log.c > > @@ -9,10 +9,10 @@ > > #include <stdbool.h> > > #include <stdio.h> > > #include <stdarg.h> > > -#include <syslog.h> > > #include "fuse_log.h" > > > > static bool use_syslog; > > +int current_log_level = LOG_INFO; > > Shall we make it static var which won't populate other files? It's used in passthrouth_ll.c (the end of this patch), "-d" sets current_log_level to LOG_DEBUG. > > Jun Thanks for the review! Eryu > > > > > void fuse_log_enable_syslog(void) > > { > > @@ -24,10 +24,13 @@ void fuse_log_enable_syslog(void) > > openlog("virtiofsd", LOG_PID, LOG_DAEMON); > > } > > > > -static void fuse_vlog(int priority, const char *fmt, va_list ap) > > +static void fuse_vlog(int target_level, const char *fmt, va_list ap) > > { > > + if (current_log_level < target_level) > > + return; > > + > > if (use_syslog) { > > - vsyslog(priority, fmt, ap); > > + vsyslog(target_level, fmt, ap); > > } else { > > vfprintf(stderr, fmt, ap); > > } > > diff --git a/contrib/virtiofsd/fuse_log.h b/contrib/virtiofsd/fuse_log.h > > index 3c22928d2b1d..c4dfc921b6d8 100644 > > --- a/contrib/virtiofsd/fuse_log.h > > +++ b/contrib/virtiofsd/fuse_log.h > > @@ -9,8 +9,12 @@ > > #ifndef FUSE_LOG_H > > #define FUSE_LOG_H > > > > +#include <syslog.h> > > #include "qemu/compiler.h" > > > > +/* Current log level */ > > +extern int current_log_level; > > + > > void fuse_log_enable_syslog(void); > > void fuse_err(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > > void fuse_warning(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > > diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > > index 8d3f141d23cf..7eec2680b6de 100644 > > --- a/contrib/virtiofsd/fuse_lowlevel.c > > +++ b/contrib/virtiofsd/fuse_lowlevel.c > > @@ -155,19 +155,17 @@ static int fuse_send_msg(struct fuse_session *se, struct fuse_chan *ch, > > struct fuse_out_header *out = iov[0].iov_base; > > > > out->len = iov_length(iov, count); > > - if (se->debug) { > > - if (out->unique == 0) { > > - fuse_debug("NOTIFY: code=%d length=%u\n", > > - out->error, out->len); > > - } else if (out->error) { > > - fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > > - (unsigned long long) out->unique, > > - out->error, strerror(-out->error), > > - out->len); > > - } else { > > - fuse_debug(" unique: %llu, success, outsize: %i\n", > > - (unsigned long long) out->unique, out->len); > > - } > > + if (out->unique == 0) { > > + fuse_debug("NOTIFY: code=%d length=%u\n", > > + out->error, out->len); > > + } else if (out->error) { > > + fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > > + (unsigned long long) out->unique, > > + out->error, strerror(-out->error), > > + out->len); > > + } else { > > + fuse_debug(" unique: %llu, success, outsize: %i\n", > > + (unsigned long long) out->unique, out->len); > > } > > > > if (fuse_lowlevel_is_virtio(se)) { > > @@ -1668,9 +1666,7 @@ static void do_interrupt(fuse_req_t req, fuse_ino_t nodeid, > > return; > > } > > > > - if (se->debug) > > - fuse_debug("INTERRUPT: %llu\n", > > - (unsigned long long) arg->unique); > > + fuse_debug("INTERRUPT: %llu\n", (unsigned long long) arg->unique); > > > > req->u.i.unique = arg->unique; > > > > @@ -1952,13 +1948,10 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > > } > > } > > > > - if (se->debug) { > > - fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > > - if (arg->major == 7 && arg->minor >= 6) { > > - fuse_debug("flags=0x%08x\n", arg->flags); > > - fuse_debug("max_readahead=0x%08x\n", > > - arg->max_readahead); > > - } > > + fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > > + if (arg->major == 7 && arg->minor >= 6) { > > + fuse_debug("flags=0x%08x\n", arg->flags); > > + fuse_debug("max_readahead=0x%08x\n", arg->max_readahead); > > } > > se->conn.proto_major = arg->major; > > se->conn.proto_minor = arg->minor; > > @@ -2135,21 +2128,14 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > > outarg.map_alignment = sysconf(_SC_PAGE_SIZE); > > } > > > > - if (se->debug) { > > - fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > > - fuse_debug(" flags=0x%08x\n", outarg.flags); > > - fuse_debug(" max_readahead=0x%08x\n", > > - outarg.max_readahead); > > - fuse_debug(" max_write=0x%08x\n", outarg.max_write); > > - fuse_debug(" max_background=%i\n", > > - outarg.max_background); > > - fuse_debug(" congestion_threshold=%i\n", > > - outarg.congestion_threshold); > > - fuse_debug(" time_gran=%u\n", > > - outarg.time_gran); > > - fuse_debug(" map_alignment=%u\n", > > - outarg.map_alignment); > > - } > > + fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > > + fuse_debug(" flags=0x%08x\n", outarg.flags); > > + fuse_debug(" max_readahead=0x%08x\n", outarg.max_readahead); > > + fuse_debug(" max_write=0x%08x\n", outarg.max_write); > > + fuse_debug(" max_background=%i\n", outarg.max_background); > > + fuse_debug(" congestion_threshold=%i\n", outarg.congestion_threshold); > > + fuse_debug(" time_gran=%u\n", outarg.time_gran); > > + fuse_debug(" map_alignment=%u\n", outarg.map_alignment); > > if (arg->minor < 5) > > outargsize = FUSE_COMPAT_INIT_OUT_SIZE; > > else if (arg->minor < 23) > > @@ -2440,13 +2426,11 @@ void fuse_session_process_buf_int(struct fuse_session *se, > > in = fuse_mbuf_iter_advance(&iter, sizeof(*in)); > > assert(in); /* caller guarantees the input buffer is large enough */ > > > > - if (se->debug) { > > - fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > > - (unsigned long long) in->unique, > > - opname((enum fuse_opcode) in->opcode), in->opcode, > > - (unsigned long long) in->nodeid, buf->size, > > - in->pid); > > - } > > + fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > > + (unsigned long long) in->unique, > > + opname((enum fuse_opcode) in->opcode), in->opcode, > > + (unsigned long long) in->nodeid, buf->size, > > + in->pid); > > > > req = fuse_ll_alloc_req(se); > > if (req == NULL) { > > @@ -2493,8 +2477,7 @@ void fuse_session_process_buf_int(struct fuse_session *se, > > // TODO: This is after a hard reboot typically, we need to do > > // a destroy, but we can't reply to this request yet so > > // we can't use do_destroy > > - if (se->debug) > > - fuse_debug("%s: reinit\n", __func__); > > + fuse_debug("%s: reinit\n", __func__); > > se->got_destroy = 1; > > se->got_init = 0; > > if (se->op.destroy) > > diff --git a/contrib/virtiofsd/fuse_lowlevel.h b/contrib/virtiofsd/fuse_lowlevel.h > > index e761d8d0e5ec..b441d3dfedeb 100644 > > --- a/contrib/virtiofsd/fuse_lowlevel.h > > +++ b/contrib/virtiofsd/fuse_lowlevel.h > > @@ -1798,6 +1798,7 @@ struct fuse_cmdline_opts { > > int show_help; > > int clone_fd; > > int syslog; > > + int log_level; > > unsigned int max_idle_threads; > > }; > > > > diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > > index 72ddf703c9d4..5b3174e4c74c 100644 > > --- a/contrib/virtiofsd/fuse_virtio.c > > +++ b/contrib/virtiofsd/fuse_virtio.c > > @@ -223,9 +223,8 @@ int virtio_send_msg(struct fuse_session *se, struct fuse_chan *ch, > > unsigned int in_num = elem->in_num; > > struct iovec *in_sg = elem->in_sg; > > size_t in_len = iov_length(in_sg, in_num); > > - if (se->debug) > > - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > - __func__, elem->index, in_num, in_len); > > + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > + __func__, elem->index, in_num, in_len); > > > > /* The elem should have room for a 'fuse_out_header' (out from fuse) > > * plus the data based on the len in the header. > > @@ -286,9 +285,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > > > out->len = tosend_len; > > > > - if (se->debug) > > - fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > > - __func__, count, len, iov_len); > > + fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > > + __func__, count, len, iov_len); > > > > /* unique == 0 is notification which we don't support */ > > assert (out->unique); > > @@ -301,9 +299,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > struct iovec *in_sg = elem->in_sg; > > size_t in_len = iov_length(in_sg, in_num); > > size_t in_len_writeable = iov_length(in_sg, in_num - bad_in_num); > > - if (se->debug) > > - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > - __func__, elem->index, in_num, in_len); > > + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > + __func__, elem->index, in_num, in_len); > > > > /* The elem should have room for a 'fuse_out_header' (out from fuse) > > * plus the data based on the len in the header. > > @@ -356,23 +353,19 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > for (i = 0, in_sg_left = 0; i < in_sg_cpy_count; i++) { > > in_sg_left += in_sg_ptr[i].iov_len; > > } > > - if (se->debug) > > - fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > > - __func__, skip_size, in_sg_cpy_count, > > - in_sg_left); > > + fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > > + __func__, skip_size, in_sg_cpy_count, in_sg_left); > > ret = preadv(buf->buf[0].fd, in_sg_ptr, in_sg_cpy_count, buf->buf[0].pos); > > > > - if (se->debug) > > - fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > > - __func__, ret, strerror(errno), len); > > + fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > > + __func__, ret, strerror(errno), len); > > if (ret == -1) { > > ret = errno; > > free(in_sg_cpy); > > goto err; > > } > > if (ret < len && ret) { > > - if (se->debug) > > - fuse_debug("%s: ret < len\n", __func__); > > + fuse_debug("%s: ret < len\n", __func__); > > /* Skip over this much next time around */ > > skip_size = ret; > > buf->buf[0].pos += ret; > > @@ -383,14 +376,12 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > } > > if (!ret) { > > /* EOF case? */ > > - if (se->debug) > > - fuse_debug("%s: !ret in_sg_left=%zd\n", > > - __func__, in_sg_left); > > + fuse_debug("%s: !ret in_sg_left=%zd\n", > > + __func__, in_sg_left); > > break; > > } > > if (ret != len) { > > - if (se->debug) > > - fuse_debug("%s: ret!=len\n", __func__); > > + fuse_debug("%s: ret!=len\n", __func__); > > ret = EIO; > > free(in_sg_cpy); > > goto err; > > @@ -410,11 +401,10 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > msg.len[0] = len; > > } > > int64_t req_res =fuse_virtio_io(se, &msg, buf->buf[0].fd); > > - if (se->debug) > > - fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > > - __func__, len, bad_in_num, > > - buf->buf[0].pos, > > - in_sg_ptr[0].iov_base, req_res); > > + fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > > + __func__, len, bad_in_num, > > + buf->buf[0].pos, > > + in_sg_ptr[0].iov_base, req_res); > > if (req_res > 0) { > > len -= msg.len[0]; > > buf->buf[0].pos += msg.len[0]; > > @@ -488,11 +478,10 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > struct iovec *out_sg = elem->out_sg; > > size_t out_len = iov_length(out_sg, out_num); > > size_t out_len_readable = iov_length(out_sg, out_num_readable); > > - if (se->debug) > > - fuse_debug("%s: elem %d: with %d out desc of length %zd" > > - " bad_in_num=%u bad_out_num=%u\n", > > - __func__, elem->index, out_num, > > - out_len, req->bad_in_num, req->bad_out_num); > > + fuse_debug("%s: elem %d: with %d out desc of length %zd" > > + " bad_in_num=%u bad_out_num=%u\n", > > + __func__, elem->index, out_num, > > + out_len, req->bad_in_num, req->bad_out_num); > > > > /* The elem should contain a 'fuse_in_header' (in to fuse) > > * plus the data based on the len in the header. > > @@ -555,11 +544,9 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > ((struct fuse_in_header *)fbuf.mem)->opcode == > > FUSE_READ && > > out_sg[1].iov_len == sizeof(struct fuse_read_in)) { > > - if (se->debug) { > > - fuse_debug("Unmappable read case " > > - "in_num=%d bad_in_num=%d\n", > > - elem->in_num, req->bad_in_num); > > - } > > + fuse_debug("Unmappable read case " > > + "in_num=%d bad_in_num=%d\n", > > + elem->in_num, req->bad_in_num); > > handled_unmappable = true; > > } > > > > @@ -581,8 +568,7 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > // data, we can just do it straight out of guest memory > > // but we must sitll copy the headers in case the guest > > // was nasty and changed them while we were using them. > > - if (se->debug) > > - fuse_debug("%s: Write special case\n", __func__); > > + fuse_debug("%s: Write special case\n", __func__); > > > > // copy the fuse_write_in header afte rthe fuse_in_header > > fbuf.mem += out_sg->iov_len; > > @@ -636,10 +622,8 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > if (!req->reply_sent) { > > struct VuVirtq *q = vu_get_queue(dev, qi->qidx); > > > > - if (se->debug) { > > - fuse_debug("%s: elem %d no reply sent\n", > > - __func__, elem->index); > > - } > > + fuse_debug("%s: elem %d no reply sent\n", > > + __func__, elem->index); > > > > pthread_rwlock_rdlock(&qi->virtio_dev->vu_dispatch_rwlock); > > pthread_mutex_lock(&qi->vq_lock); > > @@ -683,8 +667,7 @@ static void *fv_queue_thread(void *opaque) > > pf[1].events = POLLIN; > > pf[1].revents = 0; > > > > - if (qi->virtio_dev->se->debug) > > - fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > > + fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > > int poll_res = ppoll(pf, 2, NULL, NULL); > > > > if (poll_res == -1) { > > @@ -712,9 +695,8 @@ static void *fv_queue_thread(void *opaque) > > break; > > } > > assert(pf[0].revents & POLLIN); > > - if (qi->virtio_dev->se->debug) > > - fuse_debug("%s: Got queue event on Queue %d\n", > > - __func__, qi->qidx); > > + fuse_debug("%s: Got queue event on Queue %d\n", > > + __func__, qi->qidx); > > > > eventfd_t evalue; > > if (eventfd_read(qi->kick_fd, &evalue)) { > > @@ -728,15 +710,13 @@ static void *fv_queue_thread(void *opaque) > > > > pthread_mutex_lock(&qi->vq_lock); > > > > - if (se->debug) { > > - /* out is from guest, in is too guest */ > > - unsigned int in_bytes, out_bytes; > > - vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > > + /* out is from guest, in is too guest */ > > + unsigned int in_bytes, out_bytes; > > + vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > > > > - fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > > - __func__, qi->qidx, (size_t)evalue, in_bytes, > > - out_bytes); > > - } > > + fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > > + __func__, qi->qidx, (size_t)evalue, in_bytes, > > + out_bytes); > > > > while (1) { > > unsigned int bad_in_num = 0, bad_out_num = 0; > > @@ -871,8 +851,7 @@ int virtio_loop(struct fuse_session *se) > > pf[0].events = POLLIN; > > pf[0].revents = 0; > > > > - if (se->debug) > > - fuse_debug("%s: Waiting for VU event\n", __func__); > > + fuse_debug("%s: Waiting for VU event\n", __func__); > > int poll_res = ppoll(pf, 1, NULL, NULL); > > > > if (poll_res == -1) { > > @@ -890,8 +869,7 @@ int virtio_loop(struct fuse_session *se) > > break; > > } > > assert(pf[0].revents & POLLIN); > > - if (se->debug) > > - fuse_debug("%s: Got VU event\n", __func__); > > + fuse_debug("%s: Got VU event\n", __func__); > > > > /* Mutual exclusion with fv_queue_thread() */ > > ret = pthread_rwlock_wrlock(&se->virtio_dev->vu_dispatch_rwlock); > > @@ -1058,9 +1036,7 @@ ssize_t fuse_virtio_write(fuse_req_t req, > > msg.flags[0] = VHOST_USER_FS_FLAG_MAP_W; > > > > int64_t result = fuse_virtio_io(req->se, &msg, dst->fd); > > - if (req->se->debug) { > > - fuse_debug("%s: result=%ld\n", __func__, result); > > - } > > + fuse_debug("%s: result=%ld\n", __func__, result); > > return result; > > } > > > > diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > > index 5eae1f530aae..dc80100e8594 100644 > > --- a/contrib/virtiofsd/helper.c > > +++ b/contrib/virtiofsd/helper.c > > @@ -27,6 +27,8 @@ > > > > #define FUSE_HELPER_OPT(t, p) \ > > { t, offsetof(struct fuse_cmdline_opts, p), 1 } > > +#define FUSE_HELPER_OPT_VALUE(t, p, v) \ > > + { t, offsetof(struct fuse_cmdline_opts, p), v } > > > > static const struct fuse_opt fuse_helper_opts[] = { > > FUSE_HELPER_OPT("-h", show_help), > > @@ -50,6 +52,10 @@ static const struct fuse_opt fuse_helper_opts[] = { > > FUSE_HELPER_OPT("clone_fd", clone_fd), > > FUSE_HELPER_OPT("max_idle_threads=%u", max_idle_threads), > > FUSE_HELPER_OPT("--syslog", syslog), > > + FUSE_HELPER_OPT_VALUE("log_level=debug", log_level, LOG_DEBUG), > > + FUSE_HELPER_OPT_VALUE("log_level=info", log_level, LOG_INFO), > > + FUSE_HELPER_OPT_VALUE("log_level=warn", log_level, LOG_WARNING), > > + FUSE_HELPER_OPT_VALUE("log_level=err", log_level, LOG_ERR), > > FUSE_OPT_END > > }; > > > > @@ -137,7 +143,9 @@ void fuse_cmdline_help(void) > > " -o clone_fd use separate fuse device fd for each thread\n" > > " (may improve performance)\n" > > " -o max_idle_threads the maximum number of idle worker threads\n" > > - " allowed (default: 10)\n"); > > + " allowed (default: 10)\n" > > + " -o log_level=<level> log level, default to \"info\"\n" > > + " level could be one of \"debug, info, warn, err\"\n"); > > } > > > > static int fuse_helper_opt_proc(void *data, const char *arg, int key, > > diff --git a/contrib/virtiofsd/passthrough_ll.c b/contrib/virtiofsd/passthrough_ll.c > > index 321bbb20be65..583e9685161f 100644 > > --- a/contrib/virtiofsd/passthrough_ll.c > > +++ b/contrib/virtiofsd/passthrough_ll.c > > @@ -36,6 +36,7 @@ > > > > #include "fuse_virtio.h" > > #include "fuse_lowlevel.h" > > +#include "fuse_log.h" > > #include <unistd.h> > > #include <stdlib.h> > > #include <stdio.h> > > @@ -421,11 +422,6 @@ static int lo_fd(fuse_req_t req, fuse_ino_t ino) > > return fd; > > } > > > > -static bool lo_debug(fuse_req_t req) > > -{ > > - return lo_data(req)->debug != 0; > > -} > > - > > static void lo_init(void *userdata, > > struct fuse_conn_info *conn) > > { > > @@ -436,18 +432,15 @@ static void lo_init(void *userdata, > > > > if (lo->writeback && > > conn->capable & FUSE_CAP_WRITEBACK_CACHE) { > > - if (lo->debug) > > - fuse_debug("lo_init: activating writeback\n"); > > + fuse_debug("lo_init: activating writeback\n"); > > conn->want |= FUSE_CAP_WRITEBACK_CACHE; > > } > > if (conn->capable & FUSE_CAP_FLOCK_LOCKS) { > > if (lo->flock) { > > - if (lo->debug) > > - fuse_debug("lo_init: activating flock locks\n"); > > + fuse_debug("lo_init: activating flock locks\n"); > > conn->want |= FUSE_CAP_FLOCK_LOCKS; > > } else { > > - if (lo->debug) > > - fuse_debug("lo_init: disabling flock locks\n"); > > + fuse_debug("lo_init: disabling flock locks\n"); > > conn->want &= ~FUSE_CAP_FLOCK_LOCKS; > > } > > } > > @@ -455,20 +448,17 @@ static void lo_init(void *userdata, > > > > if (conn->capable & FUSE_CAP_POSIX_LOCKS) { > > if (lo->posix_lock) { > > - if (lo->debug) > > - fuse_debug("lo_init: activating posix locks\n"); > > + fuse_debug("lo_init: activating posix locks\n"); > > conn->want |= FUSE_CAP_POSIX_LOCKS; > > } else { > > - if (lo->debug) > > - fuse_debug("lo_init: disabling posix locks\n"); > > + fuse_debug("lo_init: disabling posix locks\n"); > > conn->want &= ~FUSE_CAP_POSIX_LOCKS; > > } > > } > > > > if ((lo->cache == CACHE_NONE && !lo->readdirplus_set) || > > lo->readdirplus_clear || lo->shared) { > > - if (lo->debug) > > - fuse_debug("lo_init: disabling readdirplus\n"); > > + fuse_debug("lo_init: disabling readdirplus\n"); > > conn->want &= ~FUSE_CAP_READDIRPLUS; > > } > > } > > @@ -909,12 +899,11 @@ static int lo_do_lookup(fuse_req_t req, fuse_ino_t parent, const char *name, > > lo_inode_put(lo, &inode); > > lo_inode_put(lo, &dir); > > > > - if (lo_debug(req)) > > - fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > > - (unsigned long long) parent, name, > > - (unsigned long long) e->ino, > > - (unsigned long long) e->version_offset, > > - (unsigned long long) e->initial_version); > > + fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > > + (unsigned long long) parent, name, > > + (unsigned long long) e->ino, > > + (unsigned long long) e->version_offset, > > + (unsigned long long) e->initial_version); > > > > return 0; > > > > @@ -932,9 +921,7 @@ static void lo_lookup(fuse_req_t req, fuse_ino_t parent, const char *name) > > struct fuse_entry_param e; > > int err; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", > > - parent, name); > > + fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", parent, name); > > > > /* Don't use is_safe_path_component(), allow "." and ".." for NFS export > > * support. > > @@ -1040,10 +1027,9 @@ static void lo_mknod_symlink(fuse_req_t req, fuse_ino_t parent, > > if (saverr) > > goto out; > > > > - if (lo_debug(req)) > > - fuse_debug(" %lli/%s -> %lli\n", > > - (unsigned long long) parent, name, > > - (unsigned long long) e.ino); > > + fuse_debug(" %lli/%s -> %lli\n", > > + (unsigned long long) parent, name, > > + (unsigned long long) e.ino); > > > > fuse_reply_entry(req, &e, lo->shared); > > lo_inode_put(lo, &dir); > > @@ -1149,10 +1135,9 @@ static void lo_link(fuse_req_t req, fuse_ino_t ino, fuse_ino_t parent, > > update_version(lo, inode); > > update_version(lo, parent_inode); > > > > - if (lo_debug(req)) > > - fuse_debug(" %lli/%s -> %lli\n", > > - (unsigned long long) parent, name, > > - (unsigned long long) e.ino); > > + fuse_debug(" %lli/%s -> %lli\n", > > + (unsigned long long) parent, name, > > + (unsigned long long) e.ino); > > > > fuse_reply_entry(req, &e, lo->shared); > > lo_inode_put(lo, &parent_inode); > > @@ -1355,12 +1340,10 @@ static void lo_forget_one(fuse_req_t req, fuse_ino_t ino, uint64_t nlookup) > > if (!inode) > > return; > > > > - if (lo_debug(req)) { > > - fuse_debug(" forget %lli %lli -%lli\n", > > - (unsigned long long) ino, > > - (unsigned long long) inode->nlookup, > > - (unsigned long long) nlookup); > > - } > > + fuse_debug(" forget %lli %lli -%lli\n", > > + (unsigned long long) ino, > > + (unsigned long long) inode->nlookup, > > + (unsigned long long) nlookup); > > > > unref_inode(lo, inode, nlookup); > > lo_inode_put(lo, &inode); > > @@ -1642,9 +1625,7 @@ static void lo_create(fuse_req_t req, fuse_ino_t parent, const char *name, > > int err; > > struct lo_cred old = {}; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", > > - parent, name); > > + fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", parent, name); > > > > if (!is_safe_path_component(name)) { > > fuse_reply_err(req, EINVAL); > > @@ -1744,11 +1725,10 @@ static void lo_getlk(fuse_req_t req, fuse_ino_t ino, > > struct lo_inode_plock *plock; > > int ret, saverr = 0; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > > - " owner=0x%lx, l_type=%d l_start=0x%lx" > > - " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > > - lock->l_type, lock->l_start, lock->l_len); > > + fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > > + " owner=0x%lx, l_type=%d l_start=0x%lx" > > + " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > > + lock->l_type, lock->l_start, lock->l_len); > > > > inode = lo_inode(req, ino); > > if (!inode) { > > @@ -1786,12 +1766,11 @@ static void lo_setlk(fuse_req_t req, fuse_ino_t ino, > > struct lo_inode_plock *plock; > > int ret, saverr = 0; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > > - " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > > - " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > > - lock->l_type, lock->l_pid, fi->lock_owner, sleep, > > - lock->l_whence, lock->l_start, lock->l_len); > > + fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > > + " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > > + " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > > + lock->l_type, lock->l_pid, fi->lock_owner, sleep, > > + lock->l_whence, lock->l_start, lock->l_len); > > > > if (sleep) { > > fuse_reply_err(req, EOPNOTSUPP); > > @@ -1860,9 +1839,7 @@ static void lo_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info *fi) > > char buf[64]; > > struct lo_data *lo = lo_data(req); > > > > - if (lo_debug(req)) > > - fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", > > - ino, fi->flags); > > + fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", ino, fi->flags); > > > > /* With writeback cache, kernel may send read requests even > > when userspace opened write-only */ > > @@ -1965,9 +1942,7 @@ static void lo_fsync(fuse_req_t req, fuse_ino_t ino, int datasync, > > int fd; > > char *buf; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, > > - (void *)fi); > > + fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, (void *)fi); > > > > if (!fi) { > > res = asprintf(&buf, "%i", lo_fd(req, ino)); > > @@ -1995,9 +1970,8 @@ static void lo_read(fuse_req_t req, fuse_ino_t ino, size_t size, > > { > > struct fuse_bufvec buf = FUSE_BUFVEC_INIT(size); > > > > - if (lo_debug(req)) > > - fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > > - "off=%lu)\n", ino, size, (unsigned long) offset); > > + fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > > + "off=%lu)\n", ino, size, (unsigned long) offset); > > > > buf.buf[0].flags = FUSE_BUF_IS_FD | FUSE_BUF_FD_SEEK; > > buf.buf[0].fd = lo_fi_fd(req, fi); > > @@ -2019,9 +1993,8 @@ static void lo_write_buf(fuse_req_t req, fuse_ino_t ino, > > out_buf.buf[0].fd = lo_fi_fd(req, fi); > > out_buf.buf[0].pos = off; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > > - ino, out_buf.buf[0].size, (unsigned long) off); > > + fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > > + ino, out_buf.buf[0].size, (unsigned long) off); > > > > res = fuse_buf_copy(req, &out_buf, in_buf, 0); > > if(res < 0) { > > @@ -2105,10 +2078,8 @@ static void lo_getxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > > if (!lo_data(req)->xattr) > > goto out; > > > > - if (lo_debug(req)) { > > - fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > > - ino, name, size); > > - } > > + fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > > + ino, name, size); > > > > if (inode->is_symlink) { > > /* Sorry, no race free way to getxattr on symlink. */ > > @@ -2180,10 +2151,7 @@ static void lo_listxattr(fuse_req_t req, fuse_ino_t ino, size_t size) > > if (!lo_data(req)->xattr) > > goto out; > > > > - if (lo_debug(req)) { > > - fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", > > - ino, size); > > - } > > + fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", ino, size); > > > > if (inode->is_symlink) { > > /* Sorry, no race free way to listxattr on symlink. */ > > @@ -2255,10 +2223,8 @@ static void lo_setxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > > if (!lo_data(req)->xattr) > > goto out; > > > > - if (lo_debug(req)) { > > - fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > > - ino, name, value, size); > > - } > > + fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > > + ino, name, value, size); > > > > if (inode->is_symlink) { > > /* Sorry, no race free way to removexattr on symlink. */ > > @@ -2306,10 +2272,7 @@ static void lo_removexattr(fuse_req_t req, fuse_ino_t ino, const char *name) > > if (!lo_data(req)->xattr) > > goto out; > > > > - if (lo_debug(req)) { > > - fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", > > - ino, name); > > - } > > + fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", ino, name); > > > > if (inode->is_symlink) { > > /* Sorry, no race free way to setxattr on symlink. */ > > @@ -2351,12 +2314,11 @@ static void lo_copy_file_range(fuse_req_t req, fuse_ino_t ino_in, off_t off_in, > > in_fd = lo_fi_fd(req, fi_in); > > out_fd = lo_fi_fd(req, fi_out); > > > > - if (lo_debug(req)) > > - fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > > - "off=%lu, ino=%" PRIu64 "/fd=%d, " > > - "off=%lu, size=%zd, flags=0x%x)\n", > > - ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > > - flags); > > + fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > > + "off=%lu, ino=%" PRIu64 "/fd=%d, " > > + "off=%lu, size=%zd, flags=0x%x)\n", > > + ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > > + flags); > > > > res = copy_file_range(in_fd, &off_in, out_fd, &off_out, len, flags); > > if (res < 0) > > @@ -2377,11 +2339,10 @@ static void lo_setupmapping(fuse_req_t req, fuse_ino_t ino, uint64_t foffset, > > char *buf; > > bool writable = flags & O_RDWR; > > > > - if (lo_debug(req)) > > - fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > > - " foffset=%" PRIu64 ", len=%" PRIu64 > > - ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > > - (void *)fi, foffset, len, moffset, flags); > > + fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > > + " foffset=%" PRIu64 ", len=%" PRIu64 > > + ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > > + (void *)fi, foffset, len, moffset, flags); > > > > vhu_flags = VHOST_USER_FS_FLAG_MAP_R; > > if (writable) > > @@ -2878,7 +2839,16 @@ int main(int argc, char *argv[]) > > if (fuse_opt_parse(&args, &lo, lo_opts, NULL)== -1) > > goto err_out1; > > > > + /* > > + * log_level is 0 if not configured via cmd options (0 is LOG_EMERG, > > + * and we don't use this log level). > > + */ > > + if (opts.log_level != 0) > > + current_log_level = opts.log_level; > > lo.debug = opts.debug; > > + if (lo.debug) > > + current_log_level = LOG_DEBUG; > > + > > if (lo.source) { > > struct stat stat; > > int res; > > > > _______________________________________________ > Virtio-fs mailing list > Virtio-fs@redhat.com > https://www.redhat.com/mailman/listinfo/virtio-fs ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough 2019-08-11 13:20 ` Eryu Guan @ 2019-08-11 14:32 ` piaojun 2019-08-11 15:35 ` Eryu Guan 0 siblings, 1 reply; 12+ messages in thread From: piaojun @ 2019-08-11 14:32 UTC (permalink / raw) To: Eryu Guan; +Cc: virtio-fs On 2019/8/11 21:20, Eryu Guan wrote: > On Fri, Aug 09, 2019 at 05:34:06PM +0800, piaojun wrote: >> Hi Eryu, >> >> A very big patch, and I prefer spliting into several ones. > > Most of the changes are replacing > > if (lo->debug) > fuse_debug(...); > > to > fuse_debug(...); > > But yeah, it's fine to split, one patches introduce current_log_level > related code, one does the replacements. Sounds reasonable. > >> >> On 2019/8/9 16:25, Eryu Guan wrote: >>> Introduce "-o log_level=" command line option to specify current log >>> level (priority), valid values are "debug info warn err", e.g. >>> >>> ./virtiofsd -o log_level=debug ... >>> >>> So only log priority higher than "debug" will be printed to >>> stderr/syslog. And the default level is info. >>> >>> The "-o debug"/"-d" options are kept, and imply debug log level. >> >> I wonder if this will make user confused when there are two options for >> debug. > > Forgot to mention, one reason to keep "-o debug/-d" options is try not > to break existing users, e.g. kata-runtime. But I have no strong > preference on this. Yes, compat is always important, and I have little knowledge about kata, so it would be best to reach an agreement with it. After looking though all the fuse_log codes, I come up with a new idea to do this. 1. Expand the debug in struct lo_data to *log_level* which represent err, warn, info and debug; struct lo_data { pthread_mutex_t mutex; int debug -> *log_level*; 2. Define a fuse_log_set_level() in fuse_log.c and called by passthrough_ll.c or other files. 3. As for the "-o debug/-d", I prefer to clean it up to make the usage easier. Maybe this won't do harm to the compat as virtiofsd is still in development now. But this change will need a discuss with other developers. Jun > >> >>> >>> Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> >>> --- >>> contrib/virtiofsd/fuse_log.c | 9 ++- >>> contrib/virtiofsd/fuse_log.h | 4 + >>> contrib/virtiofsd/fuse_lowlevel.c | 77 +++++++----------- >>> contrib/virtiofsd/fuse_lowlevel.h | 1 + >>> contrib/virtiofsd/fuse_virtio.c | 104 ++++++++++--------------- >>> contrib/virtiofsd/helper.c | 10 ++- >>> contrib/virtiofsd/passthrough_ll.c | 156 +++++++++++++++---------------------- >>> 7 files changed, 153 insertions(+), 208 deletions(-) >>> >>> diff --git a/contrib/virtiofsd/fuse_log.c b/contrib/virtiofsd/fuse_log.c >>> index 4eb25328721e..d54b64099a2b 100644 >>> --- a/contrib/virtiofsd/fuse_log.c >>> +++ b/contrib/virtiofsd/fuse_log.c >>> @@ -9,10 +9,10 @@ >>> #include <stdbool.h> >>> #include <stdio.h> >>> #include <stdarg.h> >>> -#include <syslog.h> >>> #include "fuse_log.h" >>> >>> static bool use_syslog; >>> +int current_log_level = LOG_INFO; >> >> Shall we make it static var which won't populate other files? > > It's used in passthrouth_ll.c (the end of this patch), "-d" sets > current_log_level to LOG_DEBUG. > >> >> Jun > > Thanks for the review! > > Eryu > >> >>> >>> void fuse_log_enable_syslog(void) >>> { >>> @@ -24,10 +24,13 @@ void fuse_log_enable_syslog(void) >>> openlog("virtiofsd", LOG_PID, LOG_DAEMON); >>> } >>> >>> -static void fuse_vlog(int priority, const char *fmt, va_list ap) >>> +static void fuse_vlog(int target_level, const char *fmt, va_list ap) >>> { >>> + if (current_log_level < target_level) >>> + return; >>> + >>> if (use_syslog) { >>> - vsyslog(priority, fmt, ap); >>> + vsyslog(target_level, fmt, ap); >>> } else { >>> vfprintf(stderr, fmt, ap); >>> } >>> diff --git a/contrib/virtiofsd/fuse_log.h b/contrib/virtiofsd/fuse_log.h >>> index 3c22928d2b1d..c4dfc921b6d8 100644 >>> --- a/contrib/virtiofsd/fuse_log.h >>> +++ b/contrib/virtiofsd/fuse_log.h >>> @@ -9,8 +9,12 @@ >>> #ifndef FUSE_LOG_H >>> #define FUSE_LOG_H >>> >>> +#include <syslog.h> >>> #include "qemu/compiler.h" >>> >>> +/* Current log level */ >>> +extern int current_log_level; >>> + >>> void fuse_log_enable_syslog(void); >>> void fuse_err(const char *fmt, ...) GCC_FMT_ATTR(1, 2); >>> void fuse_warning(const char *fmt, ...) GCC_FMT_ATTR(1, 2); >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c >>> index 8d3f141d23cf..7eec2680b6de 100644 >>> --- a/contrib/virtiofsd/fuse_lowlevel.c >>> +++ b/contrib/virtiofsd/fuse_lowlevel.c >>> @@ -155,19 +155,17 @@ static int fuse_send_msg(struct fuse_session *se, struct fuse_chan *ch, >>> struct fuse_out_header *out = iov[0].iov_base; >>> >>> out->len = iov_length(iov, count); >>> - if (se->debug) { >>> - if (out->unique == 0) { >>> - fuse_debug("NOTIFY: code=%d length=%u\n", >>> - out->error, out->len); >>> - } else if (out->error) { >>> - fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", >>> - (unsigned long long) out->unique, >>> - out->error, strerror(-out->error), >>> - out->len); >>> - } else { >>> - fuse_debug(" unique: %llu, success, outsize: %i\n", >>> - (unsigned long long) out->unique, out->len); >>> - } >>> + if (out->unique == 0) { >>> + fuse_debug("NOTIFY: code=%d length=%u\n", >>> + out->error, out->len); >>> + } else if (out->error) { >>> + fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", >>> + (unsigned long long) out->unique, >>> + out->error, strerror(-out->error), >>> + out->len); >>> + } else { >>> + fuse_debug(" unique: %llu, success, outsize: %i\n", >>> + (unsigned long long) out->unique, out->len); >>> } >>> >>> if (fuse_lowlevel_is_virtio(se)) { >>> @@ -1668,9 +1666,7 @@ static void do_interrupt(fuse_req_t req, fuse_ino_t nodeid, >>> return; >>> } >>> >>> - if (se->debug) >>> - fuse_debug("INTERRUPT: %llu\n", >>> - (unsigned long long) arg->unique); >>> + fuse_debug("INTERRUPT: %llu\n", (unsigned long long) arg->unique); >>> >>> req->u.i.unique = arg->unique; >>> >>> @@ -1952,13 +1948,10 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, >>> } >>> } >>> >>> - if (se->debug) { >>> - fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); >>> - if (arg->major == 7 && arg->minor >= 6) { >>> - fuse_debug("flags=0x%08x\n", arg->flags); >>> - fuse_debug("max_readahead=0x%08x\n", >>> - arg->max_readahead); >>> - } >>> + fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); >>> + if (arg->major == 7 && arg->minor >= 6) { >>> + fuse_debug("flags=0x%08x\n", arg->flags); >>> + fuse_debug("max_readahead=0x%08x\n", arg->max_readahead); >>> } >>> se->conn.proto_major = arg->major; >>> se->conn.proto_minor = arg->minor; >>> @@ -2135,21 +2128,14 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, >>> outarg.map_alignment = sysconf(_SC_PAGE_SIZE); >>> } >>> >>> - if (se->debug) { >>> - fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); >>> - fuse_debug(" flags=0x%08x\n", outarg.flags); >>> - fuse_debug(" max_readahead=0x%08x\n", >>> - outarg.max_readahead); >>> - fuse_debug(" max_write=0x%08x\n", outarg.max_write); >>> - fuse_debug(" max_background=%i\n", >>> - outarg.max_background); >>> - fuse_debug(" congestion_threshold=%i\n", >>> - outarg.congestion_threshold); >>> - fuse_debug(" time_gran=%u\n", >>> - outarg.time_gran); >>> - fuse_debug(" map_alignment=%u\n", >>> - outarg.map_alignment); >>> - } >>> + fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); >>> + fuse_debug(" flags=0x%08x\n", outarg.flags); >>> + fuse_debug(" max_readahead=0x%08x\n", outarg.max_readahead); >>> + fuse_debug(" max_write=0x%08x\n", outarg.max_write); >>> + fuse_debug(" max_background=%i\n", outarg.max_background); >>> + fuse_debug(" congestion_threshold=%i\n", outarg.congestion_threshold); >>> + fuse_debug(" time_gran=%u\n", outarg.time_gran); >>> + fuse_debug(" map_alignment=%u\n", outarg.map_alignment); >>> if (arg->minor < 5) >>> outargsize = FUSE_COMPAT_INIT_OUT_SIZE; >>> else if (arg->minor < 23) >>> @@ -2440,13 +2426,11 @@ void fuse_session_process_buf_int(struct fuse_session *se, >>> in = fuse_mbuf_iter_advance(&iter, sizeof(*in)); >>> assert(in); /* caller guarantees the input buffer is large enough */ >>> >>> - if (se->debug) { >>> - fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", >>> - (unsigned long long) in->unique, >>> - opname((enum fuse_opcode) in->opcode), in->opcode, >>> - (unsigned long long) in->nodeid, buf->size, >>> - in->pid); >>> - } >>> + fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", >>> + (unsigned long long) in->unique, >>> + opname((enum fuse_opcode) in->opcode), in->opcode, >>> + (unsigned long long) in->nodeid, buf->size, >>> + in->pid); >>> >>> req = fuse_ll_alloc_req(se); >>> if (req == NULL) { >>> @@ -2493,8 +2477,7 @@ void fuse_session_process_buf_int(struct fuse_session *se, >>> // TODO: This is after a hard reboot typically, we need to do >>> // a destroy, but we can't reply to this request yet so >>> // we can't use do_destroy >>> - if (se->debug) >>> - fuse_debug("%s: reinit\n", __func__); >>> + fuse_debug("%s: reinit\n", __func__); >>> se->got_destroy = 1; >>> se->got_init = 0; >>> if (se->op.destroy) >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.h b/contrib/virtiofsd/fuse_lowlevel.h >>> index e761d8d0e5ec..b441d3dfedeb 100644 >>> --- a/contrib/virtiofsd/fuse_lowlevel.h >>> +++ b/contrib/virtiofsd/fuse_lowlevel.h >>> @@ -1798,6 +1798,7 @@ struct fuse_cmdline_opts { >>> int show_help; >>> int clone_fd; >>> int syslog; >>> + int log_level; >>> unsigned int max_idle_threads; >>> }; >>> >>> diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c >>> index 72ddf703c9d4..5b3174e4c74c 100644 >>> --- a/contrib/virtiofsd/fuse_virtio.c >>> +++ b/contrib/virtiofsd/fuse_virtio.c >>> @@ -223,9 +223,8 @@ int virtio_send_msg(struct fuse_session *se, struct fuse_chan *ch, >>> unsigned int in_num = elem->in_num; >>> struct iovec *in_sg = elem->in_sg; >>> size_t in_len = iov_length(in_sg, in_num); >>> - if (se->debug) >>> - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", >>> - __func__, elem->index, in_num, in_len); >>> + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", >>> + __func__, elem->index, in_num, in_len); >>> >>> /* The elem should have room for a 'fuse_out_header' (out from fuse) >>> * plus the data based on the len in the header. >>> @@ -286,9 +285,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, >>> >>> out->len = tosend_len; >>> >>> - if (se->debug) >>> - fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", >>> - __func__, count, len, iov_len); >>> + fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", >>> + __func__, count, len, iov_len); >>> >>> /* unique == 0 is notification which we don't support */ >>> assert (out->unique); >>> @@ -301,9 +299,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, >>> struct iovec *in_sg = elem->in_sg; >>> size_t in_len = iov_length(in_sg, in_num); >>> size_t in_len_writeable = iov_length(in_sg, in_num - bad_in_num); >>> - if (se->debug) >>> - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", >>> - __func__, elem->index, in_num, in_len); >>> + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", >>> + __func__, elem->index, in_num, in_len); >>> >>> /* The elem should have room for a 'fuse_out_header' (out from fuse) >>> * plus the data based on the len in the header. >>> @@ -356,23 +353,19 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, >>> for (i = 0, in_sg_left = 0; i < in_sg_cpy_count; i++) { >>> in_sg_left += in_sg_ptr[i].iov_len; >>> } >>> - if (se->debug) >>> - fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", >>> - __func__, skip_size, in_sg_cpy_count, >>> - in_sg_left); >>> + fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", >>> + __func__, skip_size, in_sg_cpy_count, in_sg_left); >>> ret = preadv(buf->buf[0].fd, in_sg_ptr, in_sg_cpy_count, buf->buf[0].pos); >>> >>> - if (se->debug) >>> - fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", >>> - __func__, ret, strerror(errno), len); >>> + fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", >>> + __func__, ret, strerror(errno), len); >>> if (ret == -1) { >>> ret = errno; >>> free(in_sg_cpy); >>> goto err; >>> } >>> if (ret < len && ret) { >>> - if (se->debug) >>> - fuse_debug("%s: ret < len\n", __func__); >>> + fuse_debug("%s: ret < len\n", __func__); >>> /* Skip over this much next time around */ >>> skip_size = ret; >>> buf->buf[0].pos += ret; >>> @@ -383,14 +376,12 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, >>> } >>> if (!ret) { >>> /* EOF case? */ >>> - if (se->debug) >>> - fuse_debug("%s: !ret in_sg_left=%zd\n", >>> - __func__, in_sg_left); >>> + fuse_debug("%s: !ret in_sg_left=%zd\n", >>> + __func__, in_sg_left); >>> break; >>> } >>> if (ret != len) { >>> - if (se->debug) >>> - fuse_debug("%s: ret!=len\n", __func__); >>> + fuse_debug("%s: ret!=len\n", __func__); >>> ret = EIO; >>> free(in_sg_cpy); >>> goto err; >>> @@ -410,11 +401,10 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, >>> msg.len[0] = len; >>> } >>> int64_t req_res =fuse_virtio_io(se, &msg, buf->buf[0].fd); >>> - if (se->debug) >>> - fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", >>> - __func__, len, bad_in_num, >>> - buf->buf[0].pos, >>> - in_sg_ptr[0].iov_base, req_res); >>> + fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", >>> + __func__, len, bad_in_num, >>> + buf->buf[0].pos, >>> + in_sg_ptr[0].iov_base, req_res); >>> if (req_res > 0) { >>> len -= msg.len[0]; >>> buf->buf[0].pos += msg.len[0]; >>> @@ -488,11 +478,10 @@ static void fv_queue_worker(gpointer data, gpointer user_data) >>> struct iovec *out_sg = elem->out_sg; >>> size_t out_len = iov_length(out_sg, out_num); >>> size_t out_len_readable = iov_length(out_sg, out_num_readable); >>> - if (se->debug) >>> - fuse_debug("%s: elem %d: with %d out desc of length %zd" >>> - " bad_in_num=%u bad_out_num=%u\n", >>> - __func__, elem->index, out_num, >>> - out_len, req->bad_in_num, req->bad_out_num); >>> + fuse_debug("%s: elem %d: with %d out desc of length %zd" >>> + " bad_in_num=%u bad_out_num=%u\n", >>> + __func__, elem->index, out_num, >>> + out_len, req->bad_in_num, req->bad_out_num); >>> >>> /* The elem should contain a 'fuse_in_header' (in to fuse) >>> * plus the data based on the len in the header. >>> @@ -555,11 +544,9 @@ static void fv_queue_worker(gpointer data, gpointer user_data) >>> ((struct fuse_in_header *)fbuf.mem)->opcode == >>> FUSE_READ && >>> out_sg[1].iov_len == sizeof(struct fuse_read_in)) { >>> - if (se->debug) { >>> - fuse_debug("Unmappable read case " >>> - "in_num=%d bad_in_num=%d\n", >>> - elem->in_num, req->bad_in_num); >>> - } >>> + fuse_debug("Unmappable read case " >>> + "in_num=%d bad_in_num=%d\n", >>> + elem->in_num, req->bad_in_num); >>> handled_unmappable = true; >>> } >>> >>> @@ -581,8 +568,7 @@ static void fv_queue_worker(gpointer data, gpointer user_data) >>> // data, we can just do it straight out of guest memory >>> // but we must sitll copy the headers in case the guest >>> // was nasty and changed them while we were using them. >>> - if (se->debug) >>> - fuse_debug("%s: Write special case\n", __func__); >>> + fuse_debug("%s: Write special case\n", __func__); >>> >>> // copy the fuse_write_in header afte rthe fuse_in_header >>> fbuf.mem += out_sg->iov_len; >>> @@ -636,10 +622,8 @@ static void fv_queue_worker(gpointer data, gpointer user_data) >>> if (!req->reply_sent) { >>> struct VuVirtq *q = vu_get_queue(dev, qi->qidx); >>> >>> - if (se->debug) { >>> - fuse_debug("%s: elem %d no reply sent\n", >>> - __func__, elem->index); >>> - } >>> + fuse_debug("%s: elem %d no reply sent\n", >>> + __func__, elem->index); >>> >>> pthread_rwlock_rdlock(&qi->virtio_dev->vu_dispatch_rwlock); >>> pthread_mutex_lock(&qi->vq_lock); >>> @@ -683,8 +667,7 @@ static void *fv_queue_thread(void *opaque) >>> pf[1].events = POLLIN; >>> pf[1].revents = 0; >>> >>> - if (qi->virtio_dev->se->debug) >>> - fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); >>> + fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); >>> int poll_res = ppoll(pf, 2, NULL, NULL); >>> >>> if (poll_res == -1) { >>> @@ -712,9 +695,8 @@ static void *fv_queue_thread(void *opaque) >>> break; >>> } >>> assert(pf[0].revents & POLLIN); >>> - if (qi->virtio_dev->se->debug) >>> - fuse_debug("%s: Got queue event on Queue %d\n", >>> - __func__, qi->qidx); >>> + fuse_debug("%s: Got queue event on Queue %d\n", >>> + __func__, qi->qidx); >>> >>> eventfd_t evalue; >>> if (eventfd_read(qi->kick_fd, &evalue)) { >>> @@ -728,15 +710,13 @@ static void *fv_queue_thread(void *opaque) >>> >>> pthread_mutex_lock(&qi->vq_lock); >>> >>> - if (se->debug) { >>> - /* out is from guest, in is too guest */ >>> - unsigned int in_bytes, out_bytes; >>> - vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); >>> + /* out is from guest, in is too guest */ >>> + unsigned int in_bytes, out_bytes; >>> + vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); >>> >>> - fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", >>> - __func__, qi->qidx, (size_t)evalue, in_bytes, >>> - out_bytes); >>> - } >>> + fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", >>> + __func__, qi->qidx, (size_t)evalue, in_bytes, >>> + out_bytes); >>> >>> while (1) { >>> unsigned int bad_in_num = 0, bad_out_num = 0; >>> @@ -871,8 +851,7 @@ int virtio_loop(struct fuse_session *se) >>> pf[0].events = POLLIN; >>> pf[0].revents = 0; >>> >>> - if (se->debug) >>> - fuse_debug("%s: Waiting for VU event\n", __func__); >>> + fuse_debug("%s: Waiting for VU event\n", __func__); >>> int poll_res = ppoll(pf, 1, NULL, NULL); >>> >>> if (poll_res == -1) { >>> @@ -890,8 +869,7 @@ int virtio_loop(struct fuse_session *se) >>> break; >>> } >>> assert(pf[0].revents & POLLIN); >>> - if (se->debug) >>> - fuse_debug("%s: Got VU event\n", __func__); >>> + fuse_debug("%s: Got VU event\n", __func__); >>> >>> /* Mutual exclusion with fv_queue_thread() */ >>> ret = pthread_rwlock_wrlock(&se->virtio_dev->vu_dispatch_rwlock); >>> @@ -1058,9 +1036,7 @@ ssize_t fuse_virtio_write(fuse_req_t req, >>> msg.flags[0] = VHOST_USER_FS_FLAG_MAP_W; >>> >>> int64_t result = fuse_virtio_io(req->se, &msg, dst->fd); >>> - if (req->se->debug) { >>> - fuse_debug("%s: result=%ld\n", __func__, result); >>> - } >>> + fuse_debug("%s: result=%ld\n", __func__, result); >>> return result; >>> } >>> >>> diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c >>> index 5eae1f530aae..dc80100e8594 100644 >>> --- a/contrib/virtiofsd/helper.c >>> +++ b/contrib/virtiofsd/helper.c >>> @@ -27,6 +27,8 @@ >>> >>> #define FUSE_HELPER_OPT(t, p) \ >>> { t, offsetof(struct fuse_cmdline_opts, p), 1 } >>> +#define FUSE_HELPER_OPT_VALUE(t, p, v) \ >>> + { t, offsetof(struct fuse_cmdline_opts, p), v } >>> >>> static const struct fuse_opt fuse_helper_opts[] = { >>> FUSE_HELPER_OPT("-h", show_help), >>> @@ -50,6 +52,10 @@ static const struct fuse_opt fuse_helper_opts[] = { >>> FUSE_HELPER_OPT("clone_fd", clone_fd), >>> FUSE_HELPER_OPT("max_idle_threads=%u", max_idle_threads), >>> FUSE_HELPER_OPT("--syslog", syslog), >>> + FUSE_HELPER_OPT_VALUE("log_level=debug", log_level, LOG_DEBUG), >>> + FUSE_HELPER_OPT_VALUE("log_level=info", log_level, LOG_INFO), >>> + FUSE_HELPER_OPT_VALUE("log_level=warn", log_level, LOG_WARNING), >>> + FUSE_HELPER_OPT_VALUE("log_level=err", log_level, LOG_ERR), >>> FUSE_OPT_END >>> }; >>> >>> @@ -137,7 +143,9 @@ void fuse_cmdline_help(void) >>> " -o clone_fd use separate fuse device fd for each thread\n" >>> " (may improve performance)\n" >>> " -o max_idle_threads the maximum number of idle worker threads\n" >>> - " allowed (default: 10)\n"); >>> + " allowed (default: 10)\n" >>> + " -o log_level=<level> log level, default to \"info\"\n" >>> + " level could be one of \"debug, info, warn, err\"\n"); >>> } >>> >>> static int fuse_helper_opt_proc(void *data, const char *arg, int key, >>> diff --git a/contrib/virtiofsd/passthrough_ll.c b/contrib/virtiofsd/passthrough_ll.c >>> index 321bbb20be65..583e9685161f 100644 >>> --- a/contrib/virtiofsd/passthrough_ll.c >>> +++ b/contrib/virtiofsd/passthrough_ll.c >>> @@ -36,6 +36,7 @@ >>> >>> #include "fuse_virtio.h" >>> #include "fuse_lowlevel.h" >>> +#include "fuse_log.h" >>> #include <unistd.h> >>> #include <stdlib.h> >>> #include <stdio.h> >>> @@ -421,11 +422,6 @@ static int lo_fd(fuse_req_t req, fuse_ino_t ino) >>> return fd; >>> } >>> >>> -static bool lo_debug(fuse_req_t req) >>> -{ >>> - return lo_data(req)->debug != 0; >>> -} >>> - >>> static void lo_init(void *userdata, >>> struct fuse_conn_info *conn) >>> { >>> @@ -436,18 +432,15 @@ static void lo_init(void *userdata, >>> >>> if (lo->writeback && >>> conn->capable & FUSE_CAP_WRITEBACK_CACHE) { >>> - if (lo->debug) >>> - fuse_debug("lo_init: activating writeback\n"); >>> + fuse_debug("lo_init: activating writeback\n"); >>> conn->want |= FUSE_CAP_WRITEBACK_CACHE; >>> } >>> if (conn->capable & FUSE_CAP_FLOCK_LOCKS) { >>> if (lo->flock) { >>> - if (lo->debug) >>> - fuse_debug("lo_init: activating flock locks\n"); >>> + fuse_debug("lo_init: activating flock locks\n"); >>> conn->want |= FUSE_CAP_FLOCK_LOCKS; >>> } else { >>> - if (lo->debug) >>> - fuse_debug("lo_init: disabling flock locks\n"); >>> + fuse_debug("lo_init: disabling flock locks\n"); >>> conn->want &= ~FUSE_CAP_FLOCK_LOCKS; >>> } >>> } >>> @@ -455,20 +448,17 @@ static void lo_init(void *userdata, >>> >>> if (conn->capable & FUSE_CAP_POSIX_LOCKS) { >>> if (lo->posix_lock) { >>> - if (lo->debug) >>> - fuse_debug("lo_init: activating posix locks\n"); >>> + fuse_debug("lo_init: activating posix locks\n"); >>> conn->want |= FUSE_CAP_POSIX_LOCKS; >>> } else { >>> - if (lo->debug) >>> - fuse_debug("lo_init: disabling posix locks\n"); >>> + fuse_debug("lo_init: disabling posix locks\n"); >>> conn->want &= ~FUSE_CAP_POSIX_LOCKS; >>> } >>> } >>> >>> if ((lo->cache == CACHE_NONE && !lo->readdirplus_set) || >>> lo->readdirplus_clear || lo->shared) { >>> - if (lo->debug) >>> - fuse_debug("lo_init: disabling readdirplus\n"); >>> + fuse_debug("lo_init: disabling readdirplus\n"); >>> conn->want &= ~FUSE_CAP_READDIRPLUS; >>> } >>> } >>> @@ -909,12 +899,11 @@ static int lo_do_lookup(fuse_req_t req, fuse_ino_t parent, const char *name, >>> lo_inode_put(lo, &inode); >>> lo_inode_put(lo, &dir); >>> >>> - if (lo_debug(req)) >>> - fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", >>> - (unsigned long long) parent, name, >>> - (unsigned long long) e->ino, >>> - (unsigned long long) e->version_offset, >>> - (unsigned long long) e->initial_version); >>> + fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", >>> + (unsigned long long) parent, name, >>> + (unsigned long long) e->ino, >>> + (unsigned long long) e->version_offset, >>> + (unsigned long long) e->initial_version); >>> >>> return 0; >>> >>> @@ -932,9 +921,7 @@ static void lo_lookup(fuse_req_t req, fuse_ino_t parent, const char *name) >>> struct fuse_entry_param e; >>> int err; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", >>> - parent, name); >>> + fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", parent, name); >>> >>> /* Don't use is_safe_path_component(), allow "." and ".." for NFS export >>> * support. >>> @@ -1040,10 +1027,9 @@ static void lo_mknod_symlink(fuse_req_t req, fuse_ino_t parent, >>> if (saverr) >>> goto out; >>> >>> - if (lo_debug(req)) >>> - fuse_debug(" %lli/%s -> %lli\n", >>> - (unsigned long long) parent, name, >>> - (unsigned long long) e.ino); >>> + fuse_debug(" %lli/%s -> %lli\n", >>> + (unsigned long long) parent, name, >>> + (unsigned long long) e.ino); >>> >>> fuse_reply_entry(req, &e, lo->shared); >>> lo_inode_put(lo, &dir); >>> @@ -1149,10 +1135,9 @@ static void lo_link(fuse_req_t req, fuse_ino_t ino, fuse_ino_t parent, >>> update_version(lo, inode); >>> update_version(lo, parent_inode); >>> >>> - if (lo_debug(req)) >>> - fuse_debug(" %lli/%s -> %lli\n", >>> - (unsigned long long) parent, name, >>> - (unsigned long long) e.ino); >>> + fuse_debug(" %lli/%s -> %lli\n", >>> + (unsigned long long) parent, name, >>> + (unsigned long long) e.ino); >>> >>> fuse_reply_entry(req, &e, lo->shared); >>> lo_inode_put(lo, &parent_inode); >>> @@ -1355,12 +1340,10 @@ static void lo_forget_one(fuse_req_t req, fuse_ino_t ino, uint64_t nlookup) >>> if (!inode) >>> return; >>> >>> - if (lo_debug(req)) { >>> - fuse_debug(" forget %lli %lli -%lli\n", >>> - (unsigned long long) ino, >>> - (unsigned long long) inode->nlookup, >>> - (unsigned long long) nlookup); >>> - } >>> + fuse_debug(" forget %lli %lli -%lli\n", >>> + (unsigned long long) ino, >>> + (unsigned long long) inode->nlookup, >>> + (unsigned long long) nlookup); >>> >>> unref_inode(lo, inode, nlookup); >>> lo_inode_put(lo, &inode); >>> @@ -1642,9 +1625,7 @@ static void lo_create(fuse_req_t req, fuse_ino_t parent, const char *name, >>> int err; >>> struct lo_cred old = {}; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", >>> - parent, name); >>> + fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", parent, name); >>> >>> if (!is_safe_path_component(name)) { >>> fuse_reply_err(req, EINVAL); >>> @@ -1744,11 +1725,10 @@ static void lo_getlk(fuse_req_t req, fuse_ino_t ino, >>> struct lo_inode_plock *plock; >>> int ret, saverr = 0; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" >>> - " owner=0x%lx, l_type=%d l_start=0x%lx" >>> - " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, >>> - lock->l_type, lock->l_start, lock->l_len); >>> + fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" >>> + " owner=0x%lx, l_type=%d l_start=0x%lx" >>> + " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, >>> + lock->l_type, lock->l_start, lock->l_len); >>> >>> inode = lo_inode(req, ino); >>> if (!inode) { >>> @@ -1786,12 +1766,11 @@ static void lo_setlk(fuse_req_t req, fuse_ino_t ino, >>> struct lo_inode_plock *plock; >>> int ret, saverr = 0; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" >>> - " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" >>> - " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, >>> - lock->l_type, lock->l_pid, fi->lock_owner, sleep, >>> - lock->l_whence, lock->l_start, lock->l_len); >>> + fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" >>> + " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" >>> + " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, >>> + lock->l_type, lock->l_pid, fi->lock_owner, sleep, >>> + lock->l_whence, lock->l_start, lock->l_len); >>> >>> if (sleep) { >>> fuse_reply_err(req, EOPNOTSUPP); >>> @@ -1860,9 +1839,7 @@ static void lo_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info *fi) >>> char buf[64]; >>> struct lo_data *lo = lo_data(req); >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", >>> - ino, fi->flags); >>> + fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", ino, fi->flags); >>> >>> /* With writeback cache, kernel may send read requests even >>> when userspace opened write-only */ >>> @@ -1965,9 +1942,7 @@ static void lo_fsync(fuse_req_t req, fuse_ino_t ino, int datasync, >>> int fd; >>> char *buf; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, >>> - (void *)fi); >>> + fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, (void *)fi); >>> >>> if (!fi) { >>> res = asprintf(&buf, "%i", lo_fd(req, ino)); >>> @@ -1995,9 +1970,8 @@ static void lo_read(fuse_req_t req, fuse_ino_t ino, size_t size, >>> { >>> struct fuse_bufvec buf = FUSE_BUFVEC_INIT(size); >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " >>> - "off=%lu)\n", ino, size, (unsigned long) offset); >>> + fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " >>> + "off=%lu)\n", ino, size, (unsigned long) offset); >>> >>> buf.buf[0].flags = FUSE_BUF_IS_FD | FUSE_BUF_FD_SEEK; >>> buf.buf[0].fd = lo_fi_fd(req, fi); >>> @@ -2019,9 +1993,8 @@ static void lo_write_buf(fuse_req_t req, fuse_ino_t ino, >>> out_buf.buf[0].fd = lo_fi_fd(req, fi); >>> out_buf.buf[0].pos = off; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", >>> - ino, out_buf.buf[0].size, (unsigned long) off); >>> + fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", >>> + ino, out_buf.buf[0].size, (unsigned long) off); >>> >>> res = fuse_buf_copy(req, &out_buf, in_buf, 0); >>> if(res < 0) { >>> @@ -2105,10 +2078,8 @@ static void lo_getxattr(fuse_req_t req, fuse_ino_t ino, const char *name, >>> if (!lo_data(req)->xattr) >>> goto out; >>> >>> - if (lo_debug(req)) { >>> - fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", >>> - ino, name, size); >>> - } >>> + fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", >>> + ino, name, size); >>> >>> if (inode->is_symlink) { >>> /* Sorry, no race free way to getxattr on symlink. */ >>> @@ -2180,10 +2151,7 @@ static void lo_listxattr(fuse_req_t req, fuse_ino_t ino, size_t size) >>> if (!lo_data(req)->xattr) >>> goto out; >>> >>> - if (lo_debug(req)) { >>> - fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", >>> - ino, size); >>> - } >>> + fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", ino, size); >>> >>> if (inode->is_symlink) { >>> /* Sorry, no race free way to listxattr on symlink. */ >>> @@ -2255,10 +2223,8 @@ static void lo_setxattr(fuse_req_t req, fuse_ino_t ino, const char *name, >>> if (!lo_data(req)->xattr) >>> goto out; >>> >>> - if (lo_debug(req)) { >>> - fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", >>> - ino, name, value, size); >>> - } >>> + fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", >>> + ino, name, value, size); >>> >>> if (inode->is_symlink) { >>> /* Sorry, no race free way to removexattr on symlink. */ >>> @@ -2306,10 +2272,7 @@ static void lo_removexattr(fuse_req_t req, fuse_ino_t ino, const char *name) >>> if (!lo_data(req)->xattr) >>> goto out; >>> >>> - if (lo_debug(req)) { >>> - fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", >>> - ino, name); >>> - } >>> + fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", ino, name); >>> >>> if (inode->is_symlink) { >>> /* Sorry, no race free way to setxattr on symlink. */ >>> @@ -2351,12 +2314,11 @@ static void lo_copy_file_range(fuse_req_t req, fuse_ino_t ino_in, off_t off_in, >>> in_fd = lo_fi_fd(req, fi_in); >>> out_fd = lo_fi_fd(req, fi_out); >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " >>> - "off=%lu, ino=%" PRIu64 "/fd=%d, " >>> - "off=%lu, size=%zd, flags=0x%x)\n", >>> - ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, >>> - flags); >>> + fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " >>> + "off=%lu, ino=%" PRIu64 "/fd=%d, " >>> + "off=%lu, size=%zd, flags=0x%x)\n", >>> + ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, >>> + flags); >>> >>> res = copy_file_range(in_fd, &off_in, out_fd, &off_out, len, flags); >>> if (res < 0) >>> @@ -2377,11 +2339,10 @@ static void lo_setupmapping(fuse_req_t req, fuse_ino_t ino, uint64_t foffset, >>> char *buf; >>> bool writable = flags & O_RDWR; >>> >>> - if (lo_debug(req)) >>> - fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," >>> - " foffset=%" PRIu64 ", len=%" PRIu64 >>> - ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, >>> - (void *)fi, foffset, len, moffset, flags); >>> + fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," >>> + " foffset=%" PRIu64 ", len=%" PRIu64 >>> + ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, >>> + (void *)fi, foffset, len, moffset, flags); >>> >>> vhu_flags = VHOST_USER_FS_FLAG_MAP_R; >>> if (writable) >>> @@ -2878,7 +2839,16 @@ int main(int argc, char *argv[]) >>> if (fuse_opt_parse(&args, &lo, lo_opts, NULL)== -1) >>> goto err_out1; >>> >>> + /* >>> + * log_level is 0 if not configured via cmd options (0 is LOG_EMERG, >>> + * and we don't use this log level). >>> + */ >>> + if (opts.log_level != 0) >>> + current_log_level = opts.log_level; >>> lo.debug = opts.debug; >>> + if (lo.debug) >>> + current_log_level = LOG_DEBUG; >>> + >>> if (lo.source) { >>> struct stat stat; >>> int res; >>> >> >> _______________________________________________ >> Virtio-fs mailing list >> Virtio-fs@redhat.com >> https://www.redhat.com/mailman/listinfo/virtio-fs > . > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough 2019-08-11 14:32 ` piaojun @ 2019-08-11 15:35 ` Eryu Guan 2019-08-12 2:28 ` piaojun 2019-08-15 9:45 ` Dr. David Alan Gilbert 0 siblings, 2 replies; 12+ messages in thread From: Eryu Guan @ 2019-08-11 15:35 UTC (permalink / raw) To: piaojun; +Cc: virtio-fs On Sun, Aug 11, 2019 at 10:32:16PM +0800, piaojun wrote: > > > On 2019/8/11 21:20, Eryu Guan wrote: > > On Fri, Aug 09, 2019 at 05:34:06PM +0800, piaojun wrote: > >> Hi Eryu, > >> > >> A very big patch, and I prefer spliting into several ones. > > > > Most of the changes are replacing > > > > if (lo->debug) > > fuse_debug(...); > > > > to > > fuse_debug(...); > > > > But yeah, it's fine to split, one patches introduce current_log_level > > related code, one does the replacements. > > Sounds reasonable. > > > > >> > >> On 2019/8/9 16:25, Eryu Guan wrote: > >>> Introduce "-o log_level=" command line option to specify current log > >>> level (priority), valid values are "debug info warn err", e.g. > >>> > >>> ./virtiofsd -o log_level=debug ... > >>> > >>> So only log priority higher than "debug" will be printed to > >>> stderr/syslog. And the default level is info. > >>> > >>> The "-o debug"/"-d" options are kept, and imply debug log level. > >> > >> I wonder if this will make user confused when there are two options for > >> debug. > > > > Forgot to mention, one reason to keep "-o debug/-d" options is try not > > to break existing users, e.g. kata-runtime. But I have no strong > > preference on this. > > Yes, compat is always important, and I have little knowledge about kata, > so it would be best to reach an agreement with it. > > After looking though all the fuse_log codes, I come up with a new idea > to do this. > 1. Expand the debug in struct lo_data to *log_level* which represent > err, warn, info and debug; > > struct lo_data { > pthread_mutex_t mutex; > int debug -> *log_level*; I thought about this too, but that means that fuse_debug/info/warn/err functions should take lo_data or fuse_session as argument as well, and I don't think it's worth to introduce such complexity, a global log level would be easier. And I think it's possible & easier to add support to change the log level (as a global variable) when virtiofsd is running, e.g. on SIGHUP. > > 2. Define a fuse_log_set_level() in fuse_log.c and called by > passthrough_ll.c or other files. Sounds good. > > 3. As for the "-o debug/-d", I prefer to clean it up to make the usage > easier. Maybe this won't do harm to the compat as virtiofsd is still in > development now. But this change will need a discuss with other developers. Thanks, Eryu > > Jun > > > > >> > >>> > >>> Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> > >>> --- > >>> contrib/virtiofsd/fuse_log.c | 9 ++- > >>> contrib/virtiofsd/fuse_log.h | 4 + > >>> contrib/virtiofsd/fuse_lowlevel.c | 77 +++++++----------- > >>> contrib/virtiofsd/fuse_lowlevel.h | 1 + > >>> contrib/virtiofsd/fuse_virtio.c | 104 ++++++++++--------------- > >>> contrib/virtiofsd/helper.c | 10 ++- > >>> contrib/virtiofsd/passthrough_ll.c | 156 +++++++++++++++---------------------- > >>> 7 files changed, 153 insertions(+), 208 deletions(-) > >>> > >>> diff --git a/contrib/virtiofsd/fuse_log.c b/contrib/virtiofsd/fuse_log.c > >>> index 4eb25328721e..d54b64099a2b 100644 > >>> --- a/contrib/virtiofsd/fuse_log.c > >>> +++ b/contrib/virtiofsd/fuse_log.c > >>> @@ -9,10 +9,10 @@ > >>> #include <stdbool.h> > >>> #include <stdio.h> > >>> #include <stdarg.h> > >>> -#include <syslog.h> > >>> #include "fuse_log.h" > >>> > >>> static bool use_syslog; > >>> +int current_log_level = LOG_INFO; > >> > >> Shall we make it static var which won't populate other files? > > > > It's used in passthrouth_ll.c (the end of this patch), "-d" sets > > current_log_level to LOG_DEBUG. > > > >> > >> Jun > > > > Thanks for the review! > > > > Eryu > > > >> > >>> > >>> void fuse_log_enable_syslog(void) > >>> { > >>> @@ -24,10 +24,13 @@ void fuse_log_enable_syslog(void) > >>> openlog("virtiofsd", LOG_PID, LOG_DAEMON); > >>> } > >>> > >>> -static void fuse_vlog(int priority, const char *fmt, va_list ap) > >>> +static void fuse_vlog(int target_level, const char *fmt, va_list ap) > >>> { > >>> + if (current_log_level < target_level) > >>> + return; > >>> + > >>> if (use_syslog) { > >>> - vsyslog(priority, fmt, ap); > >>> + vsyslog(target_level, fmt, ap); > >>> } else { > >>> vfprintf(stderr, fmt, ap); > >>> } > >>> diff --git a/contrib/virtiofsd/fuse_log.h b/contrib/virtiofsd/fuse_log.h > >>> index 3c22928d2b1d..c4dfc921b6d8 100644 > >>> --- a/contrib/virtiofsd/fuse_log.h > >>> +++ b/contrib/virtiofsd/fuse_log.h > >>> @@ -9,8 +9,12 @@ > >>> #ifndef FUSE_LOG_H > >>> #define FUSE_LOG_H > >>> > >>> +#include <syslog.h> > >>> #include "qemu/compiler.h" > >>> > >>> +/* Current log level */ > >>> +extern int current_log_level; > >>> + > >>> void fuse_log_enable_syslog(void); > >>> void fuse_err(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > >>> void fuse_warning(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > >>> index 8d3f141d23cf..7eec2680b6de 100644 > >>> --- a/contrib/virtiofsd/fuse_lowlevel.c > >>> +++ b/contrib/virtiofsd/fuse_lowlevel.c > >>> @@ -155,19 +155,17 @@ static int fuse_send_msg(struct fuse_session *se, struct fuse_chan *ch, > >>> struct fuse_out_header *out = iov[0].iov_base; > >>> > >>> out->len = iov_length(iov, count); > >>> - if (se->debug) { > >>> - if (out->unique == 0) { > >>> - fuse_debug("NOTIFY: code=%d length=%u\n", > >>> - out->error, out->len); > >>> - } else if (out->error) { > >>> - fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > >>> - (unsigned long long) out->unique, > >>> - out->error, strerror(-out->error), > >>> - out->len); > >>> - } else { > >>> - fuse_debug(" unique: %llu, success, outsize: %i\n", > >>> - (unsigned long long) out->unique, out->len); > >>> - } > >>> + if (out->unique == 0) { > >>> + fuse_debug("NOTIFY: code=%d length=%u\n", > >>> + out->error, out->len); > >>> + } else if (out->error) { > >>> + fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > >>> + (unsigned long long) out->unique, > >>> + out->error, strerror(-out->error), > >>> + out->len); > >>> + } else { > >>> + fuse_debug(" unique: %llu, success, outsize: %i\n", > >>> + (unsigned long long) out->unique, out->len); > >>> } > >>> > >>> if (fuse_lowlevel_is_virtio(se)) { > >>> @@ -1668,9 +1666,7 @@ static void do_interrupt(fuse_req_t req, fuse_ino_t nodeid, > >>> return; > >>> } > >>> > >>> - if (se->debug) > >>> - fuse_debug("INTERRUPT: %llu\n", > >>> - (unsigned long long) arg->unique); > >>> + fuse_debug("INTERRUPT: %llu\n", (unsigned long long) arg->unique); > >>> > >>> req->u.i.unique = arg->unique; > >>> > >>> @@ -1952,13 +1948,10 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > >>> } > >>> } > >>> > >>> - if (se->debug) { > >>> - fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > >>> - if (arg->major == 7 && arg->minor >= 6) { > >>> - fuse_debug("flags=0x%08x\n", arg->flags); > >>> - fuse_debug("max_readahead=0x%08x\n", > >>> - arg->max_readahead); > >>> - } > >>> + fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > >>> + if (arg->major == 7 && arg->minor >= 6) { > >>> + fuse_debug("flags=0x%08x\n", arg->flags); > >>> + fuse_debug("max_readahead=0x%08x\n", arg->max_readahead); > >>> } > >>> se->conn.proto_major = arg->major; > >>> se->conn.proto_minor = arg->minor; > >>> @@ -2135,21 +2128,14 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > >>> outarg.map_alignment = sysconf(_SC_PAGE_SIZE); > >>> } > >>> > >>> - if (se->debug) { > >>> - fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > >>> - fuse_debug(" flags=0x%08x\n", outarg.flags); > >>> - fuse_debug(" max_readahead=0x%08x\n", > >>> - outarg.max_readahead); > >>> - fuse_debug(" max_write=0x%08x\n", outarg.max_write); > >>> - fuse_debug(" max_background=%i\n", > >>> - outarg.max_background); > >>> - fuse_debug(" congestion_threshold=%i\n", > >>> - outarg.congestion_threshold); > >>> - fuse_debug(" time_gran=%u\n", > >>> - outarg.time_gran); > >>> - fuse_debug(" map_alignment=%u\n", > >>> - outarg.map_alignment); > >>> - } > >>> + fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > >>> + fuse_debug(" flags=0x%08x\n", outarg.flags); > >>> + fuse_debug(" max_readahead=0x%08x\n", outarg.max_readahead); > >>> + fuse_debug(" max_write=0x%08x\n", outarg.max_write); > >>> + fuse_debug(" max_background=%i\n", outarg.max_background); > >>> + fuse_debug(" congestion_threshold=%i\n", outarg.congestion_threshold); > >>> + fuse_debug(" time_gran=%u\n", outarg.time_gran); > >>> + fuse_debug(" map_alignment=%u\n", outarg.map_alignment); > >>> if (arg->minor < 5) > >>> outargsize = FUSE_COMPAT_INIT_OUT_SIZE; > >>> else if (arg->minor < 23) > >>> @@ -2440,13 +2426,11 @@ void fuse_session_process_buf_int(struct fuse_session *se, > >>> in = fuse_mbuf_iter_advance(&iter, sizeof(*in)); > >>> assert(in); /* caller guarantees the input buffer is large enough */ > >>> > >>> - if (se->debug) { > >>> - fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > >>> - (unsigned long long) in->unique, > >>> - opname((enum fuse_opcode) in->opcode), in->opcode, > >>> - (unsigned long long) in->nodeid, buf->size, > >>> - in->pid); > >>> - } > >>> + fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > >>> + (unsigned long long) in->unique, > >>> + opname((enum fuse_opcode) in->opcode), in->opcode, > >>> + (unsigned long long) in->nodeid, buf->size, > >>> + in->pid); > >>> > >>> req = fuse_ll_alloc_req(se); > >>> if (req == NULL) { > >>> @@ -2493,8 +2477,7 @@ void fuse_session_process_buf_int(struct fuse_session *se, > >>> // TODO: This is after a hard reboot typically, we need to do > >>> // a destroy, but we can't reply to this request yet so > >>> // we can't use do_destroy > >>> - if (se->debug) > >>> - fuse_debug("%s: reinit\n", __func__); > >>> + fuse_debug("%s: reinit\n", __func__); > >>> se->got_destroy = 1; > >>> se->got_init = 0; > >>> if (se->op.destroy) > >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.h b/contrib/virtiofsd/fuse_lowlevel.h > >>> index e761d8d0e5ec..b441d3dfedeb 100644 > >>> --- a/contrib/virtiofsd/fuse_lowlevel.h > >>> +++ b/contrib/virtiofsd/fuse_lowlevel.h > >>> @@ -1798,6 +1798,7 @@ struct fuse_cmdline_opts { > >>> int show_help; > >>> int clone_fd; > >>> int syslog; > >>> + int log_level; > >>> unsigned int max_idle_threads; > >>> }; > >>> > >>> diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > >>> index 72ddf703c9d4..5b3174e4c74c 100644 > >>> --- a/contrib/virtiofsd/fuse_virtio.c > >>> +++ b/contrib/virtiofsd/fuse_virtio.c > >>> @@ -223,9 +223,8 @@ int virtio_send_msg(struct fuse_session *se, struct fuse_chan *ch, > >>> unsigned int in_num = elem->in_num; > >>> struct iovec *in_sg = elem->in_sg; > >>> size_t in_len = iov_length(in_sg, in_num); > >>> - if (se->debug) > >>> - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > >>> - __func__, elem->index, in_num, in_len); > >>> + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > >>> + __func__, elem->index, in_num, in_len); > >>> > >>> /* The elem should have room for a 'fuse_out_header' (out from fuse) > >>> * plus the data based on the len in the header. > >>> @@ -286,9 +285,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > >>> > >>> out->len = tosend_len; > >>> > >>> - if (se->debug) > >>> - fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > >>> - __func__, count, len, iov_len); > >>> + fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > >>> + __func__, count, len, iov_len); > >>> > >>> /* unique == 0 is notification which we don't support */ > >>> assert (out->unique); > >>> @@ -301,9 +299,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > >>> struct iovec *in_sg = elem->in_sg; > >>> size_t in_len = iov_length(in_sg, in_num); > >>> size_t in_len_writeable = iov_length(in_sg, in_num - bad_in_num); > >>> - if (se->debug) > >>> - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > >>> - __func__, elem->index, in_num, in_len); > >>> + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > >>> + __func__, elem->index, in_num, in_len); > >>> > >>> /* The elem should have room for a 'fuse_out_header' (out from fuse) > >>> * plus the data based on the len in the header. > >>> @@ -356,23 +353,19 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > >>> for (i = 0, in_sg_left = 0; i < in_sg_cpy_count; i++) { > >>> in_sg_left += in_sg_ptr[i].iov_len; > >>> } > >>> - if (se->debug) > >>> - fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > >>> - __func__, skip_size, in_sg_cpy_count, > >>> - in_sg_left); > >>> + fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > >>> + __func__, skip_size, in_sg_cpy_count, in_sg_left); > >>> ret = preadv(buf->buf[0].fd, in_sg_ptr, in_sg_cpy_count, buf->buf[0].pos); > >>> > >>> - if (se->debug) > >>> - fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > >>> - __func__, ret, strerror(errno), len); > >>> + fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > >>> + __func__, ret, strerror(errno), len); > >>> if (ret == -1) { > >>> ret = errno; > >>> free(in_sg_cpy); > >>> goto err; > >>> } > >>> if (ret < len && ret) { > >>> - if (se->debug) > >>> - fuse_debug("%s: ret < len\n", __func__); > >>> + fuse_debug("%s: ret < len\n", __func__); > >>> /* Skip over this much next time around */ > >>> skip_size = ret; > >>> buf->buf[0].pos += ret; > >>> @@ -383,14 +376,12 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > >>> } > >>> if (!ret) { > >>> /* EOF case? */ > >>> - if (se->debug) > >>> - fuse_debug("%s: !ret in_sg_left=%zd\n", > >>> - __func__, in_sg_left); > >>> + fuse_debug("%s: !ret in_sg_left=%zd\n", > >>> + __func__, in_sg_left); > >>> break; > >>> } > >>> if (ret != len) { > >>> - if (se->debug) > >>> - fuse_debug("%s: ret!=len\n", __func__); > >>> + fuse_debug("%s: ret!=len\n", __func__); > >>> ret = EIO; > >>> free(in_sg_cpy); > >>> goto err; > >>> @@ -410,11 +401,10 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > >>> msg.len[0] = len; > >>> } > >>> int64_t req_res =fuse_virtio_io(se, &msg, buf->buf[0].fd); > >>> - if (se->debug) > >>> - fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > >>> - __func__, len, bad_in_num, > >>> - buf->buf[0].pos, > >>> - in_sg_ptr[0].iov_base, req_res); > >>> + fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > >>> + __func__, len, bad_in_num, > >>> + buf->buf[0].pos, > >>> + in_sg_ptr[0].iov_base, req_res); > >>> if (req_res > 0) { > >>> len -= msg.len[0]; > >>> buf->buf[0].pos += msg.len[0]; > >>> @@ -488,11 +478,10 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > >>> struct iovec *out_sg = elem->out_sg; > >>> size_t out_len = iov_length(out_sg, out_num); > >>> size_t out_len_readable = iov_length(out_sg, out_num_readable); > >>> - if (se->debug) > >>> - fuse_debug("%s: elem %d: with %d out desc of length %zd" > >>> - " bad_in_num=%u bad_out_num=%u\n", > >>> - __func__, elem->index, out_num, > >>> - out_len, req->bad_in_num, req->bad_out_num); > >>> + fuse_debug("%s: elem %d: with %d out desc of length %zd" > >>> + " bad_in_num=%u bad_out_num=%u\n", > >>> + __func__, elem->index, out_num, > >>> + out_len, req->bad_in_num, req->bad_out_num); > >>> > >>> /* The elem should contain a 'fuse_in_header' (in to fuse) > >>> * plus the data based on the len in the header. > >>> @@ -555,11 +544,9 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > >>> ((struct fuse_in_header *)fbuf.mem)->opcode == > >>> FUSE_READ && > >>> out_sg[1].iov_len == sizeof(struct fuse_read_in)) { > >>> - if (se->debug) { > >>> - fuse_debug("Unmappable read case " > >>> - "in_num=%d bad_in_num=%d\n", > >>> - elem->in_num, req->bad_in_num); > >>> - } > >>> + fuse_debug("Unmappable read case " > >>> + "in_num=%d bad_in_num=%d\n", > >>> + elem->in_num, req->bad_in_num); > >>> handled_unmappable = true; > >>> } > >>> > >>> @@ -581,8 +568,7 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > >>> // data, we can just do it straight out of guest memory > >>> // but we must sitll copy the headers in case the guest > >>> // was nasty and changed them while we were using them. > >>> - if (se->debug) > >>> - fuse_debug("%s: Write special case\n", __func__); > >>> + fuse_debug("%s: Write special case\n", __func__); > >>> > >>> // copy the fuse_write_in header afte rthe fuse_in_header > >>> fbuf.mem += out_sg->iov_len; > >>> @@ -636,10 +622,8 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > >>> if (!req->reply_sent) { > >>> struct VuVirtq *q = vu_get_queue(dev, qi->qidx); > >>> > >>> - if (se->debug) { > >>> - fuse_debug("%s: elem %d no reply sent\n", > >>> - __func__, elem->index); > >>> - } > >>> + fuse_debug("%s: elem %d no reply sent\n", > >>> + __func__, elem->index); > >>> > >>> pthread_rwlock_rdlock(&qi->virtio_dev->vu_dispatch_rwlock); > >>> pthread_mutex_lock(&qi->vq_lock); > >>> @@ -683,8 +667,7 @@ static void *fv_queue_thread(void *opaque) > >>> pf[1].events = POLLIN; > >>> pf[1].revents = 0; > >>> > >>> - if (qi->virtio_dev->se->debug) > >>> - fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > >>> + fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > >>> int poll_res = ppoll(pf, 2, NULL, NULL); > >>> > >>> if (poll_res == -1) { > >>> @@ -712,9 +695,8 @@ static void *fv_queue_thread(void *opaque) > >>> break; > >>> } > >>> assert(pf[0].revents & POLLIN); > >>> - if (qi->virtio_dev->se->debug) > >>> - fuse_debug("%s: Got queue event on Queue %d\n", > >>> - __func__, qi->qidx); > >>> + fuse_debug("%s: Got queue event on Queue %d\n", > >>> + __func__, qi->qidx); > >>> > >>> eventfd_t evalue; > >>> if (eventfd_read(qi->kick_fd, &evalue)) { > >>> @@ -728,15 +710,13 @@ static void *fv_queue_thread(void *opaque) > >>> > >>> pthread_mutex_lock(&qi->vq_lock); > >>> > >>> - if (se->debug) { > >>> - /* out is from guest, in is too guest */ > >>> - unsigned int in_bytes, out_bytes; > >>> - vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > >>> + /* out is from guest, in is too guest */ > >>> + unsigned int in_bytes, out_bytes; > >>> + vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > >>> > >>> - fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > >>> - __func__, qi->qidx, (size_t)evalue, in_bytes, > >>> - out_bytes); > >>> - } > >>> + fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > >>> + __func__, qi->qidx, (size_t)evalue, in_bytes, > >>> + out_bytes); > >>> > >>> while (1) { > >>> unsigned int bad_in_num = 0, bad_out_num = 0; > >>> @@ -871,8 +851,7 @@ int virtio_loop(struct fuse_session *se) > >>> pf[0].events = POLLIN; > >>> pf[0].revents = 0; > >>> > >>> - if (se->debug) > >>> - fuse_debug("%s: Waiting for VU event\n", __func__); > >>> + fuse_debug("%s: Waiting for VU event\n", __func__); > >>> int poll_res = ppoll(pf, 1, NULL, NULL); > >>> > >>> if (poll_res == -1) { > >>> @@ -890,8 +869,7 @@ int virtio_loop(struct fuse_session *se) > >>> break; > >>> } > >>> assert(pf[0].revents & POLLIN); > >>> - if (se->debug) > >>> - fuse_debug("%s: Got VU event\n", __func__); > >>> + fuse_debug("%s: Got VU event\n", __func__); > >>> > >>> /* Mutual exclusion with fv_queue_thread() */ > >>> ret = pthread_rwlock_wrlock(&se->virtio_dev->vu_dispatch_rwlock); > >>> @@ -1058,9 +1036,7 @@ ssize_t fuse_virtio_write(fuse_req_t req, > >>> msg.flags[0] = VHOST_USER_FS_FLAG_MAP_W; > >>> > >>> int64_t result = fuse_virtio_io(req->se, &msg, dst->fd); > >>> - if (req->se->debug) { > >>> - fuse_debug("%s: result=%ld\n", __func__, result); > >>> - } > >>> + fuse_debug("%s: result=%ld\n", __func__, result); > >>> return result; > >>> } > >>> > >>> diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > >>> index 5eae1f530aae..dc80100e8594 100644 > >>> --- a/contrib/virtiofsd/helper.c > >>> +++ b/contrib/virtiofsd/helper.c > >>> @@ -27,6 +27,8 @@ > >>> > >>> #define FUSE_HELPER_OPT(t, p) \ > >>> { t, offsetof(struct fuse_cmdline_opts, p), 1 } > >>> +#define FUSE_HELPER_OPT_VALUE(t, p, v) \ > >>> + { t, offsetof(struct fuse_cmdline_opts, p), v } > >>> > >>> static const struct fuse_opt fuse_helper_opts[] = { > >>> FUSE_HELPER_OPT("-h", show_help), > >>> @@ -50,6 +52,10 @@ static const struct fuse_opt fuse_helper_opts[] = { > >>> FUSE_HELPER_OPT("clone_fd", clone_fd), > >>> FUSE_HELPER_OPT("max_idle_threads=%u", max_idle_threads), > >>> FUSE_HELPER_OPT("--syslog", syslog), > >>> + FUSE_HELPER_OPT_VALUE("log_level=debug", log_level, LOG_DEBUG), > >>> + FUSE_HELPER_OPT_VALUE("log_level=info", log_level, LOG_INFO), > >>> + FUSE_HELPER_OPT_VALUE("log_level=warn", log_level, LOG_WARNING), > >>> + FUSE_HELPER_OPT_VALUE("log_level=err", log_level, LOG_ERR), > >>> FUSE_OPT_END > >>> }; > >>> > >>> @@ -137,7 +143,9 @@ void fuse_cmdline_help(void) > >>> " -o clone_fd use separate fuse device fd for each thread\n" > >>> " (may improve performance)\n" > >>> " -o max_idle_threads the maximum number of idle worker threads\n" > >>> - " allowed (default: 10)\n"); > >>> + " allowed (default: 10)\n" > >>> + " -o log_level=<level> log level, default to \"info\"\n" > >>> + " level could be one of \"debug, info, warn, err\"\n"); > >>> } > >>> > >>> static int fuse_helper_opt_proc(void *data, const char *arg, int key, > >>> diff --git a/contrib/virtiofsd/passthrough_ll.c b/contrib/virtiofsd/passthrough_ll.c > >>> index 321bbb20be65..583e9685161f 100644 > >>> --- a/contrib/virtiofsd/passthrough_ll.c > >>> +++ b/contrib/virtiofsd/passthrough_ll.c > >>> @@ -36,6 +36,7 @@ > >>> > >>> #include "fuse_virtio.h" > >>> #include "fuse_lowlevel.h" > >>> +#include "fuse_log.h" > >>> #include <unistd.h> > >>> #include <stdlib.h> > >>> #include <stdio.h> > >>> @@ -421,11 +422,6 @@ static int lo_fd(fuse_req_t req, fuse_ino_t ino) > >>> return fd; > >>> } > >>> > >>> -static bool lo_debug(fuse_req_t req) > >>> -{ > >>> - return lo_data(req)->debug != 0; > >>> -} > >>> - > >>> static void lo_init(void *userdata, > >>> struct fuse_conn_info *conn) > >>> { > >>> @@ -436,18 +432,15 @@ static void lo_init(void *userdata, > >>> > >>> if (lo->writeback && > >>> conn->capable & FUSE_CAP_WRITEBACK_CACHE) { > >>> - if (lo->debug) > >>> - fuse_debug("lo_init: activating writeback\n"); > >>> + fuse_debug("lo_init: activating writeback\n"); > >>> conn->want |= FUSE_CAP_WRITEBACK_CACHE; > >>> } > >>> if (conn->capable & FUSE_CAP_FLOCK_LOCKS) { > >>> if (lo->flock) { > >>> - if (lo->debug) > >>> - fuse_debug("lo_init: activating flock locks\n"); > >>> + fuse_debug("lo_init: activating flock locks\n"); > >>> conn->want |= FUSE_CAP_FLOCK_LOCKS; > >>> } else { > >>> - if (lo->debug) > >>> - fuse_debug("lo_init: disabling flock locks\n"); > >>> + fuse_debug("lo_init: disabling flock locks\n"); > >>> conn->want &= ~FUSE_CAP_FLOCK_LOCKS; > >>> } > >>> } > >>> @@ -455,20 +448,17 @@ static void lo_init(void *userdata, > >>> > >>> if (conn->capable & FUSE_CAP_POSIX_LOCKS) { > >>> if (lo->posix_lock) { > >>> - if (lo->debug) > >>> - fuse_debug("lo_init: activating posix locks\n"); > >>> + fuse_debug("lo_init: activating posix locks\n"); > >>> conn->want |= FUSE_CAP_POSIX_LOCKS; > >>> } else { > >>> - if (lo->debug) > >>> - fuse_debug("lo_init: disabling posix locks\n"); > >>> + fuse_debug("lo_init: disabling posix locks\n"); > >>> conn->want &= ~FUSE_CAP_POSIX_LOCKS; > >>> } > >>> } > >>> > >>> if ((lo->cache == CACHE_NONE && !lo->readdirplus_set) || > >>> lo->readdirplus_clear || lo->shared) { > >>> - if (lo->debug) > >>> - fuse_debug("lo_init: disabling readdirplus\n"); > >>> + fuse_debug("lo_init: disabling readdirplus\n"); > >>> conn->want &= ~FUSE_CAP_READDIRPLUS; > >>> } > >>> } > >>> @@ -909,12 +899,11 @@ static int lo_do_lookup(fuse_req_t req, fuse_ino_t parent, const char *name, > >>> lo_inode_put(lo, &inode); > >>> lo_inode_put(lo, &dir); > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > >>> - (unsigned long long) parent, name, > >>> - (unsigned long long) e->ino, > >>> - (unsigned long long) e->version_offset, > >>> - (unsigned long long) e->initial_version); > >>> + fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > >>> + (unsigned long long) parent, name, > >>> + (unsigned long long) e->ino, > >>> + (unsigned long long) e->version_offset, > >>> + (unsigned long long) e->initial_version); > >>> > >>> return 0; > >>> > >>> @@ -932,9 +921,7 @@ static void lo_lookup(fuse_req_t req, fuse_ino_t parent, const char *name) > >>> struct fuse_entry_param e; > >>> int err; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", > >>> - parent, name); > >>> + fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", parent, name); > >>> > >>> /* Don't use is_safe_path_component(), allow "." and ".." for NFS export > >>> * support. > >>> @@ -1040,10 +1027,9 @@ static void lo_mknod_symlink(fuse_req_t req, fuse_ino_t parent, > >>> if (saverr) > >>> goto out; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug(" %lli/%s -> %lli\n", > >>> - (unsigned long long) parent, name, > >>> - (unsigned long long) e.ino); > >>> + fuse_debug(" %lli/%s -> %lli\n", > >>> + (unsigned long long) parent, name, > >>> + (unsigned long long) e.ino); > >>> > >>> fuse_reply_entry(req, &e, lo->shared); > >>> lo_inode_put(lo, &dir); > >>> @@ -1149,10 +1135,9 @@ static void lo_link(fuse_req_t req, fuse_ino_t ino, fuse_ino_t parent, > >>> update_version(lo, inode); > >>> update_version(lo, parent_inode); > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug(" %lli/%s -> %lli\n", > >>> - (unsigned long long) parent, name, > >>> - (unsigned long long) e.ino); > >>> + fuse_debug(" %lli/%s -> %lli\n", > >>> + (unsigned long long) parent, name, > >>> + (unsigned long long) e.ino); > >>> > >>> fuse_reply_entry(req, &e, lo->shared); > >>> lo_inode_put(lo, &parent_inode); > >>> @@ -1355,12 +1340,10 @@ static void lo_forget_one(fuse_req_t req, fuse_ino_t ino, uint64_t nlookup) > >>> if (!inode) > >>> return; > >>> > >>> - if (lo_debug(req)) { > >>> - fuse_debug(" forget %lli %lli -%lli\n", > >>> - (unsigned long long) ino, > >>> - (unsigned long long) inode->nlookup, > >>> - (unsigned long long) nlookup); > >>> - } > >>> + fuse_debug(" forget %lli %lli -%lli\n", > >>> + (unsigned long long) ino, > >>> + (unsigned long long) inode->nlookup, > >>> + (unsigned long long) nlookup); > >>> > >>> unref_inode(lo, inode, nlookup); > >>> lo_inode_put(lo, &inode); > >>> @@ -1642,9 +1625,7 @@ static void lo_create(fuse_req_t req, fuse_ino_t parent, const char *name, > >>> int err; > >>> struct lo_cred old = {}; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", > >>> - parent, name); > >>> + fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", parent, name); > >>> > >>> if (!is_safe_path_component(name)) { > >>> fuse_reply_err(req, EINVAL); > >>> @@ -1744,11 +1725,10 @@ static void lo_getlk(fuse_req_t req, fuse_ino_t ino, > >>> struct lo_inode_plock *plock; > >>> int ret, saverr = 0; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > >>> - " owner=0x%lx, l_type=%d l_start=0x%lx" > >>> - " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > >>> - lock->l_type, lock->l_start, lock->l_len); > >>> + fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > >>> + " owner=0x%lx, l_type=%d l_start=0x%lx" > >>> + " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > >>> + lock->l_type, lock->l_start, lock->l_len); > >>> > >>> inode = lo_inode(req, ino); > >>> if (!inode) { > >>> @@ -1786,12 +1766,11 @@ static void lo_setlk(fuse_req_t req, fuse_ino_t ino, > >>> struct lo_inode_plock *plock; > >>> int ret, saverr = 0; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > >>> - " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > >>> - " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > >>> - lock->l_type, lock->l_pid, fi->lock_owner, sleep, > >>> - lock->l_whence, lock->l_start, lock->l_len); > >>> + fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > >>> + " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > >>> + " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > >>> + lock->l_type, lock->l_pid, fi->lock_owner, sleep, > >>> + lock->l_whence, lock->l_start, lock->l_len); > >>> > >>> if (sleep) { > >>> fuse_reply_err(req, EOPNOTSUPP); > >>> @@ -1860,9 +1839,7 @@ static void lo_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info *fi) > >>> char buf[64]; > >>> struct lo_data *lo = lo_data(req); > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", > >>> - ino, fi->flags); > >>> + fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", ino, fi->flags); > >>> > >>> /* With writeback cache, kernel may send read requests even > >>> when userspace opened write-only */ > >>> @@ -1965,9 +1942,7 @@ static void lo_fsync(fuse_req_t req, fuse_ino_t ino, int datasync, > >>> int fd; > >>> char *buf; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, > >>> - (void *)fi); > >>> + fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, (void *)fi); > >>> > >>> if (!fi) { > >>> res = asprintf(&buf, "%i", lo_fd(req, ino)); > >>> @@ -1995,9 +1970,8 @@ static void lo_read(fuse_req_t req, fuse_ino_t ino, size_t size, > >>> { > >>> struct fuse_bufvec buf = FUSE_BUFVEC_INIT(size); > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > >>> - "off=%lu)\n", ino, size, (unsigned long) offset); > >>> + fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > >>> + "off=%lu)\n", ino, size, (unsigned long) offset); > >>> > >>> buf.buf[0].flags = FUSE_BUF_IS_FD | FUSE_BUF_FD_SEEK; > >>> buf.buf[0].fd = lo_fi_fd(req, fi); > >>> @@ -2019,9 +1993,8 @@ static void lo_write_buf(fuse_req_t req, fuse_ino_t ino, > >>> out_buf.buf[0].fd = lo_fi_fd(req, fi); > >>> out_buf.buf[0].pos = off; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > >>> - ino, out_buf.buf[0].size, (unsigned long) off); > >>> + fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > >>> + ino, out_buf.buf[0].size, (unsigned long) off); > >>> > >>> res = fuse_buf_copy(req, &out_buf, in_buf, 0); > >>> if(res < 0) { > >>> @@ -2105,10 +2078,8 @@ static void lo_getxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > >>> if (!lo_data(req)->xattr) > >>> goto out; > >>> > >>> - if (lo_debug(req)) { > >>> - fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > >>> - ino, name, size); > >>> - } > >>> + fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > >>> + ino, name, size); > >>> > >>> if (inode->is_symlink) { > >>> /* Sorry, no race free way to getxattr on symlink. */ > >>> @@ -2180,10 +2151,7 @@ static void lo_listxattr(fuse_req_t req, fuse_ino_t ino, size_t size) > >>> if (!lo_data(req)->xattr) > >>> goto out; > >>> > >>> - if (lo_debug(req)) { > >>> - fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", > >>> - ino, size); > >>> - } > >>> + fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", ino, size); > >>> > >>> if (inode->is_symlink) { > >>> /* Sorry, no race free way to listxattr on symlink. */ > >>> @@ -2255,10 +2223,8 @@ static void lo_setxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > >>> if (!lo_data(req)->xattr) > >>> goto out; > >>> > >>> - if (lo_debug(req)) { > >>> - fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > >>> - ino, name, value, size); > >>> - } > >>> + fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > >>> + ino, name, value, size); > >>> > >>> if (inode->is_symlink) { > >>> /* Sorry, no race free way to removexattr on symlink. */ > >>> @@ -2306,10 +2272,7 @@ static void lo_removexattr(fuse_req_t req, fuse_ino_t ino, const char *name) > >>> if (!lo_data(req)->xattr) > >>> goto out; > >>> > >>> - if (lo_debug(req)) { > >>> - fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", > >>> - ino, name); > >>> - } > >>> + fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", ino, name); > >>> > >>> if (inode->is_symlink) { > >>> /* Sorry, no race free way to setxattr on symlink. */ > >>> @@ -2351,12 +2314,11 @@ static void lo_copy_file_range(fuse_req_t req, fuse_ino_t ino_in, off_t off_in, > >>> in_fd = lo_fi_fd(req, fi_in); > >>> out_fd = lo_fi_fd(req, fi_out); > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > >>> - "off=%lu, ino=%" PRIu64 "/fd=%d, " > >>> - "off=%lu, size=%zd, flags=0x%x)\n", > >>> - ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > >>> - flags); > >>> + fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > >>> + "off=%lu, ino=%" PRIu64 "/fd=%d, " > >>> + "off=%lu, size=%zd, flags=0x%x)\n", > >>> + ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > >>> + flags); > >>> > >>> res = copy_file_range(in_fd, &off_in, out_fd, &off_out, len, flags); > >>> if (res < 0) > >>> @@ -2377,11 +2339,10 @@ static void lo_setupmapping(fuse_req_t req, fuse_ino_t ino, uint64_t foffset, > >>> char *buf; > >>> bool writable = flags & O_RDWR; > >>> > >>> - if (lo_debug(req)) > >>> - fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > >>> - " foffset=%" PRIu64 ", len=%" PRIu64 > >>> - ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > >>> - (void *)fi, foffset, len, moffset, flags); > >>> + fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > >>> + " foffset=%" PRIu64 ", len=%" PRIu64 > >>> + ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > >>> + (void *)fi, foffset, len, moffset, flags); > >>> > >>> vhu_flags = VHOST_USER_FS_FLAG_MAP_R; > >>> if (writable) > >>> @@ -2878,7 +2839,16 @@ int main(int argc, char *argv[]) > >>> if (fuse_opt_parse(&args, &lo, lo_opts, NULL)== -1) > >>> goto err_out1; > >>> > >>> + /* > >>> + * log_level is 0 if not configured via cmd options (0 is LOG_EMERG, > >>> + * and we don't use this log level). > >>> + */ > >>> + if (opts.log_level != 0) > >>> + current_log_level = opts.log_level; > >>> lo.debug = opts.debug; > >>> + if (lo.debug) > >>> + current_log_level = LOG_DEBUG; > >>> + > >>> if (lo.source) { > >>> struct stat stat; > >>> int res; > >>> > >> > >> _______________________________________________ > >> Virtio-fs mailing list > >> Virtio-fs@redhat.com > >> https://www.redhat.com/mailman/listinfo/virtio-fs > > . > > ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough 2019-08-11 15:35 ` Eryu Guan @ 2019-08-12 2:28 ` piaojun 2019-08-15 9:45 ` Dr. David Alan Gilbert 1 sibling, 0 replies; 12+ messages in thread From: piaojun @ 2019-08-12 2:28 UTC (permalink / raw) To: Eryu Guan; +Cc: virtio-fs On 2019/8/11 23:35, Eryu Guan wrote: > On Sun, Aug 11, 2019 at 10:32:16PM +0800, piaojun wrote: >> >> >> On 2019/8/11 21:20, Eryu Guan wrote: >>> On Fri, Aug 09, 2019 at 05:34:06PM +0800, piaojun wrote: >>>> Hi Eryu, >>>> >>>> A very big patch, and I prefer spliting into several ones. >>> >>> Most of the changes are replacing >>> >>> if (lo->debug) >>> fuse_debug(...); >>> >>> to >>> fuse_debug(...); >>> >>> But yeah, it's fine to split, one patches introduce current_log_level >>> related code, one does the replacements. >> >> Sounds reasonable. >> >>> >>>> >>>> On 2019/8/9 16:25, Eryu Guan wrote: >>>>> Introduce "-o log_level=" command line option to specify current log >>>>> level (priority), valid values are "debug info warn err", e.g. >>>>> >>>>> ./virtiofsd -o log_level=debug ... >>>>> >>>>> So only log priority higher than "debug" will be printed to >>>>> stderr/syslog. And the default level is info. >>>>> >>>>> The "-o debug"/"-d" options are kept, and imply debug log level. >>>> >>>> I wonder if this will make user confused when there are two options for >>>> debug. >>> >>> Forgot to mention, one reason to keep "-o debug/-d" options is try not >>> to break existing users, e.g. kata-runtime. But I have no strong >>> preference on this. >> >> Yes, compat is always important, and I have little knowledge about kata, >> so it would be best to reach an agreement with it. >> >> After looking though all the fuse_log codes, I come up with a new idea >> to do this. >> 1. Expand the debug in struct lo_data to *log_level* which represent >> err, warn, info and debug; >> >> struct lo_data { >> pthread_mutex_t mutex; >> int debug -> *log_level*; > > I thought about this too, but that means that fuse_debug/info/warn/err > functions should take lo_data or fuse_session as argument as well, and I > don't think it's worth to introduce such complexity, a global log level > would be easier. And I think it's possible & easier to add support to > change the log level (as a global variable) when virtiofsd is running, > e.g. on SIGHUP. Perhaps you did not get my point, and we may just use lo_data to set *current_log_level* once, no need always pass it. We'd better do little harm do the origin code struct if possible. Jun ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough 2019-08-11 15:35 ` Eryu Guan 2019-08-12 2:28 ` piaojun @ 2019-08-15 9:45 ` Dr. David Alan Gilbert 1 sibling, 0 replies; 12+ messages in thread From: Dr. David Alan Gilbert @ 2019-08-15 9:45 UTC (permalink / raw) To: Eryu Guan; +Cc: virtio-fs * Eryu Guan (guaneryu@gmail.com) wrote: > On Sun, Aug 11, 2019 at 10:32:16PM +0800, piaojun wrote: > > > > > > On 2019/8/11 21:20, Eryu Guan wrote: > > > On Fri, Aug 09, 2019 at 05:34:06PM +0800, piaojun wrote: > > >> Hi Eryu, > > >> > > >> A very big patch, and I prefer spliting into several ones. > > > > > > Most of the changes are replacing > > > > > > if (lo->debug) > > > fuse_debug(...); > > > > > > to > > > fuse_debug(...); > > > > > > But yeah, it's fine to split, one patches introduce current_log_level > > > related code, one does the replacements. > > > > Sounds reasonable. > > > > > > > >> > > >> On 2019/8/9 16:25, Eryu Guan wrote: > > >>> Introduce "-o log_level=" command line option to specify current log > > >>> level (priority), valid values are "debug info warn err", e.g. > > >>> > > >>> ./virtiofsd -o log_level=debug ... > > >>> > > >>> So only log priority higher than "debug" will be printed to > > >>> stderr/syslog. And the default level is info. > > >>> > > >>> The "-o debug"/"-d" options are kept, and imply debug log level. > > >> > > >> I wonder if this will make user confused when there are two options for > > >> debug. > > > > > > Forgot to mention, one reason to keep "-o debug/-d" options is try not > > > to break existing users, e.g. kata-runtime. But I have no strong > > > preference on this. > > > > Yes, compat is always important, and I have little knowledge about kata, > > so it would be best to reach an agreement with it. > > > > After looking though all the fuse_log codes, I come up with a new idea > > to do this. > > 1. Expand the debug in struct lo_data to *log_level* which represent > > err, warn, info and debug; > > > > struct lo_data { > > pthread_mutex_t mutex; > > int debug -> *log_level*; > > I thought about this too, but that means that fuse_debug/info/warn/err > functions should take lo_data or fuse_session as argument as well, and I > don't think it's worth to introduce such complexity, a global log level > would be easier. And I think it's possible & easier to add support to > change the log level (as a global variable) when virtiofsd is running, > e.g. on SIGHUP. Yes, lets keep this simple; one debug variable is enough. Dave > > > > 2. Define a fuse_log_set_level() in fuse_log.c and called by > > passthrough_ll.c or other files. > > Sounds good. > > > > > 3. As for the "-o debug/-d", I prefer to clean it up to make the usage > > easier. Maybe this won't do harm to the compat as virtiofsd is still in > > development now. But this change will need a discuss with other developers. > > Thanks, > Eryu > > > > > Jun > > > > > > > >> > > >>> > > >>> Signed-off-by: Eryu Guan <eguan@linux.alibaba.com> > > >>> --- > > >>> contrib/virtiofsd/fuse_log.c | 9 ++- > > >>> contrib/virtiofsd/fuse_log.h | 4 + > > >>> contrib/virtiofsd/fuse_lowlevel.c | 77 +++++++----------- > > >>> contrib/virtiofsd/fuse_lowlevel.h | 1 + > > >>> contrib/virtiofsd/fuse_virtio.c | 104 ++++++++++--------------- > > >>> contrib/virtiofsd/helper.c | 10 ++- > > >>> contrib/virtiofsd/passthrough_ll.c | 156 +++++++++++++++---------------------- > > >>> 7 files changed, 153 insertions(+), 208 deletions(-) > > >>> > > >>> diff --git a/contrib/virtiofsd/fuse_log.c b/contrib/virtiofsd/fuse_log.c > > >>> index 4eb25328721e..d54b64099a2b 100644 > > >>> --- a/contrib/virtiofsd/fuse_log.c > > >>> +++ b/contrib/virtiofsd/fuse_log.c > > >>> @@ -9,10 +9,10 @@ > > >>> #include <stdbool.h> > > >>> #include <stdio.h> > > >>> #include <stdarg.h> > > >>> -#include <syslog.h> > > >>> #include "fuse_log.h" > > >>> > > >>> static bool use_syslog; > > >>> +int current_log_level = LOG_INFO; > > >> > > >> Shall we make it static var which won't populate other files? > > > > > > It's used in passthrouth_ll.c (the end of this patch), "-d" sets > > > current_log_level to LOG_DEBUG. > > > > > >> > > >> Jun > > > > > > Thanks for the review! > > > > > > Eryu > > > > > >> > > >>> > > >>> void fuse_log_enable_syslog(void) > > >>> { > > >>> @@ -24,10 +24,13 @@ void fuse_log_enable_syslog(void) > > >>> openlog("virtiofsd", LOG_PID, LOG_DAEMON); > > >>> } > > >>> > > >>> -static void fuse_vlog(int priority, const char *fmt, va_list ap) > > >>> +static void fuse_vlog(int target_level, const char *fmt, va_list ap) > > >>> { > > >>> + if (current_log_level < target_level) > > >>> + return; > > >>> + > > >>> if (use_syslog) { > > >>> - vsyslog(priority, fmt, ap); > > >>> + vsyslog(target_level, fmt, ap); > > >>> } else { > > >>> vfprintf(stderr, fmt, ap); > > >>> } > > >>> diff --git a/contrib/virtiofsd/fuse_log.h b/contrib/virtiofsd/fuse_log.h > > >>> index 3c22928d2b1d..c4dfc921b6d8 100644 > > >>> --- a/contrib/virtiofsd/fuse_log.h > > >>> +++ b/contrib/virtiofsd/fuse_log.h > > >>> @@ -9,8 +9,12 @@ > > >>> #ifndef FUSE_LOG_H > > >>> #define FUSE_LOG_H > > >>> > > >>> +#include <syslog.h> > > >>> #include "qemu/compiler.h" > > >>> > > >>> +/* Current log level */ > > >>> +extern int current_log_level; > > >>> + > > >>> void fuse_log_enable_syslog(void); > > >>> void fuse_err(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > > >>> void fuse_warning(const char *fmt, ...) GCC_FMT_ATTR(1, 2); > > >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.c b/contrib/virtiofsd/fuse_lowlevel.c > > >>> index 8d3f141d23cf..7eec2680b6de 100644 > > >>> --- a/contrib/virtiofsd/fuse_lowlevel.c > > >>> +++ b/contrib/virtiofsd/fuse_lowlevel.c > > >>> @@ -155,19 +155,17 @@ static int fuse_send_msg(struct fuse_session *se, struct fuse_chan *ch, > > >>> struct fuse_out_header *out = iov[0].iov_base; > > >>> > > >>> out->len = iov_length(iov, count); > > >>> - if (se->debug) { > > >>> - if (out->unique == 0) { > > >>> - fuse_debug("NOTIFY: code=%d length=%u\n", > > >>> - out->error, out->len); > > >>> - } else if (out->error) { > > >>> - fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > > >>> - (unsigned long long) out->unique, > > >>> - out->error, strerror(-out->error), > > >>> - out->len); > > >>> - } else { > > >>> - fuse_debug(" unique: %llu, success, outsize: %i\n", > > >>> - (unsigned long long) out->unique, out->len); > > >>> - } > > >>> + if (out->unique == 0) { > > >>> + fuse_debug("NOTIFY: code=%d length=%u\n", > > >>> + out->error, out->len); > > >>> + } else if (out->error) { > > >>> + fuse_debug(" unique: %llu, error: %i (%s), outsize: %i\n", > > >>> + (unsigned long long) out->unique, > > >>> + out->error, strerror(-out->error), > > >>> + out->len); > > >>> + } else { > > >>> + fuse_debug(" unique: %llu, success, outsize: %i\n", > > >>> + (unsigned long long) out->unique, out->len); > > >>> } > > >>> > > >>> if (fuse_lowlevel_is_virtio(se)) { > > >>> @@ -1668,9 +1666,7 @@ static void do_interrupt(fuse_req_t req, fuse_ino_t nodeid, > > >>> return; > > >>> } > > >>> > > >>> - if (se->debug) > > >>> - fuse_debug("INTERRUPT: %llu\n", > > >>> - (unsigned long long) arg->unique); > > >>> + fuse_debug("INTERRUPT: %llu\n", (unsigned long long) arg->unique); > > >>> > > >>> req->u.i.unique = arg->unique; > > >>> > > >>> @@ -1952,13 +1948,10 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > > >>> } > > >>> } > > >>> > > >>> - if (se->debug) { > > >>> - fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > > >>> - if (arg->major == 7 && arg->minor >= 6) { > > >>> - fuse_debug("flags=0x%08x\n", arg->flags); > > >>> - fuse_debug("max_readahead=0x%08x\n", > > >>> - arg->max_readahead); > > >>> - } > > >>> + fuse_debug("INIT: %u.%u\n", arg->major, arg->minor); > > >>> + if (arg->major == 7 && arg->minor >= 6) { > > >>> + fuse_debug("flags=0x%08x\n", arg->flags); > > >>> + fuse_debug("max_readahead=0x%08x\n", arg->max_readahead); > > >>> } > > >>> se->conn.proto_major = arg->major; > > >>> se->conn.proto_minor = arg->minor; > > >>> @@ -2135,21 +2128,14 @@ static void do_init(fuse_req_t req, fuse_ino_t nodeid, > > >>> outarg.map_alignment = sysconf(_SC_PAGE_SIZE); > > >>> } > > >>> > > >>> - if (se->debug) { > > >>> - fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > > >>> - fuse_debug(" flags=0x%08x\n", outarg.flags); > > >>> - fuse_debug(" max_readahead=0x%08x\n", > > >>> - outarg.max_readahead); > > >>> - fuse_debug(" max_write=0x%08x\n", outarg.max_write); > > >>> - fuse_debug(" max_background=%i\n", > > >>> - outarg.max_background); > > >>> - fuse_debug(" congestion_threshold=%i\n", > > >>> - outarg.congestion_threshold); > > >>> - fuse_debug(" time_gran=%u\n", > > >>> - outarg.time_gran); > > >>> - fuse_debug(" map_alignment=%u\n", > > >>> - outarg.map_alignment); > > >>> - } > > >>> + fuse_debug(" INIT: %u.%u\n", outarg.major, outarg.minor); > > >>> + fuse_debug(" flags=0x%08x\n", outarg.flags); > > >>> + fuse_debug(" max_readahead=0x%08x\n", outarg.max_readahead); > > >>> + fuse_debug(" max_write=0x%08x\n", outarg.max_write); > > >>> + fuse_debug(" max_background=%i\n", outarg.max_background); > > >>> + fuse_debug(" congestion_threshold=%i\n", outarg.congestion_threshold); > > >>> + fuse_debug(" time_gran=%u\n", outarg.time_gran); > > >>> + fuse_debug(" map_alignment=%u\n", outarg.map_alignment); > > >>> if (arg->minor < 5) > > >>> outargsize = FUSE_COMPAT_INIT_OUT_SIZE; > > >>> else if (arg->minor < 23) > > >>> @@ -2440,13 +2426,11 @@ void fuse_session_process_buf_int(struct fuse_session *se, > > >>> in = fuse_mbuf_iter_advance(&iter, sizeof(*in)); > > >>> assert(in); /* caller guarantees the input buffer is large enough */ > > >>> > > >>> - if (se->debug) { > > >>> - fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > > >>> - (unsigned long long) in->unique, > > >>> - opname((enum fuse_opcode) in->opcode), in->opcode, > > >>> - (unsigned long long) in->nodeid, buf->size, > > >>> - in->pid); > > >>> - } > > >>> + fuse_debug("unique: %llu, opcode: %s (%i), nodeid: %llu, insize: %zu, pid: %u\n", > > >>> + (unsigned long long) in->unique, > > >>> + opname((enum fuse_opcode) in->opcode), in->opcode, > > >>> + (unsigned long long) in->nodeid, buf->size, > > >>> + in->pid); > > >>> > > >>> req = fuse_ll_alloc_req(se); > > >>> if (req == NULL) { > > >>> @@ -2493,8 +2477,7 @@ void fuse_session_process_buf_int(struct fuse_session *se, > > >>> // TODO: This is after a hard reboot typically, we need to do > > >>> // a destroy, but we can't reply to this request yet so > > >>> // we can't use do_destroy > > >>> - if (se->debug) > > >>> - fuse_debug("%s: reinit\n", __func__); > > >>> + fuse_debug("%s: reinit\n", __func__); > > >>> se->got_destroy = 1; > > >>> se->got_init = 0; > > >>> if (se->op.destroy) > > >>> diff --git a/contrib/virtiofsd/fuse_lowlevel.h b/contrib/virtiofsd/fuse_lowlevel.h > > >>> index e761d8d0e5ec..b441d3dfedeb 100644 > > >>> --- a/contrib/virtiofsd/fuse_lowlevel.h > > >>> +++ b/contrib/virtiofsd/fuse_lowlevel.h > > >>> @@ -1798,6 +1798,7 @@ struct fuse_cmdline_opts { > > >>> int show_help; > > >>> int clone_fd; > > >>> int syslog; > > >>> + int log_level; > > >>> unsigned int max_idle_threads; > > >>> }; > > >>> > > >>> diff --git a/contrib/virtiofsd/fuse_virtio.c b/contrib/virtiofsd/fuse_virtio.c > > >>> index 72ddf703c9d4..5b3174e4c74c 100644 > > >>> --- a/contrib/virtiofsd/fuse_virtio.c > > >>> +++ b/contrib/virtiofsd/fuse_virtio.c > > >>> @@ -223,9 +223,8 @@ int virtio_send_msg(struct fuse_session *se, struct fuse_chan *ch, > > >>> unsigned int in_num = elem->in_num; > > >>> struct iovec *in_sg = elem->in_sg; > > >>> size_t in_len = iov_length(in_sg, in_num); > > >>> - if (se->debug) > > >>> - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > >>> - __func__, elem->index, in_num, in_len); > > >>> + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > >>> + __func__, elem->index, in_num, in_len); > > >>> > > >>> /* The elem should have room for a 'fuse_out_header' (out from fuse) > > >>> * plus the data based on the len in the header. > > >>> @@ -286,9 +285,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > >>> > > >>> out->len = tosend_len; > > >>> > > >>> - if (se->debug) > > >>> - fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > > >>> - __func__, count, len, iov_len); > > >>> + fuse_debug("%s: count=%d len=%zd iov_len=%zd \n", > > >>> + __func__, count, len, iov_len); > > >>> > > >>> /* unique == 0 is notification which we don't support */ > > >>> assert (out->unique); > > >>> @@ -301,9 +299,8 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > >>> struct iovec *in_sg = elem->in_sg; > > >>> size_t in_len = iov_length(in_sg, in_num); > > >>> size_t in_len_writeable = iov_length(in_sg, in_num - bad_in_num); > > >>> - if (se->debug) > > >>> - fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > >>> - __func__, elem->index, in_num, in_len); > > >>> + fuse_debug("%s: elem %d: with %d in desc of length %zd\n", > > >>> + __func__, elem->index, in_num, in_len); > > >>> > > >>> /* The elem should have room for a 'fuse_out_header' (out from fuse) > > >>> * plus the data based on the len in the header. > > >>> @@ -356,23 +353,19 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > >>> for (i = 0, in_sg_left = 0; i < in_sg_cpy_count; i++) { > > >>> in_sg_left += in_sg_ptr[i].iov_len; > > >>> } > > >>> - if (se->debug) > > >>> - fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > > >>> - __func__, skip_size, in_sg_cpy_count, > > >>> - in_sg_left); > > >>> + fuse_debug("%s: after skip skip_size=%zd in_sg_cpy_count=%d in_sg_left=%zd\n", > > >>> + __func__, skip_size, in_sg_cpy_count, in_sg_left); > > >>> ret = preadv(buf->buf[0].fd, in_sg_ptr, in_sg_cpy_count, buf->buf[0].pos); > > >>> > > >>> - if (se->debug) > > >>> - fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > > >>> - __func__, ret, strerror(errno), len); > > >>> + fuse_debug("%s: preadv_res=%d(%s) len=%zd\n", > > >>> + __func__, ret, strerror(errno), len); > > >>> if (ret == -1) { > > >>> ret = errno; > > >>> free(in_sg_cpy); > > >>> goto err; > > >>> } > > >>> if (ret < len && ret) { > > >>> - if (se->debug) > > >>> - fuse_debug("%s: ret < len\n", __func__); > > >>> + fuse_debug("%s: ret < len\n", __func__); > > >>> /* Skip over this much next time around */ > > >>> skip_size = ret; > > >>> buf->buf[0].pos += ret; > > >>> @@ -383,14 +376,12 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > >>> } > > >>> if (!ret) { > > >>> /* EOF case? */ > > >>> - if (se->debug) > > >>> - fuse_debug("%s: !ret in_sg_left=%zd\n", > > >>> - __func__, in_sg_left); > > >>> + fuse_debug("%s: !ret in_sg_left=%zd\n", > > >>> + __func__, in_sg_left); > > >>> break; > > >>> } > > >>> if (ret != len) { > > >>> - if (se->debug) > > >>> - fuse_debug("%s: ret!=len\n", __func__); > > >>> + fuse_debug("%s: ret!=len\n", __func__); > > >>> ret = EIO; > > >>> free(in_sg_cpy); > > >>> goto err; > > >>> @@ -410,11 +401,10 @@ int virtio_send_data_iov(struct fuse_session *se, struct fuse_chan *ch, > > >>> msg.len[0] = len; > > >>> } > > >>> int64_t req_res =fuse_virtio_io(se, &msg, buf->buf[0].fd); > > >>> - if (se->debug) > > >>> - fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > > >>> - __func__, len, bad_in_num, > > >>> - buf->buf[0].pos, > > >>> - in_sg_ptr[0].iov_base, req_res); > > >>> + fuse_debug("%s: bad loop; len=%zd bad_in_num=%d fd_offset=%zd c_offset=%p req_res=%ld\n", > > >>> + __func__, len, bad_in_num, > > >>> + buf->buf[0].pos, > > >>> + in_sg_ptr[0].iov_base, req_res); > > >>> if (req_res > 0) { > > >>> len -= msg.len[0]; > > >>> buf->buf[0].pos += msg.len[0]; > > >>> @@ -488,11 +478,10 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > >>> struct iovec *out_sg = elem->out_sg; > > >>> size_t out_len = iov_length(out_sg, out_num); > > >>> size_t out_len_readable = iov_length(out_sg, out_num_readable); > > >>> - if (se->debug) > > >>> - fuse_debug("%s: elem %d: with %d out desc of length %zd" > > >>> - " bad_in_num=%u bad_out_num=%u\n", > > >>> - __func__, elem->index, out_num, > > >>> - out_len, req->bad_in_num, req->bad_out_num); > > >>> + fuse_debug("%s: elem %d: with %d out desc of length %zd" > > >>> + " bad_in_num=%u bad_out_num=%u\n", > > >>> + __func__, elem->index, out_num, > > >>> + out_len, req->bad_in_num, req->bad_out_num); > > >>> > > >>> /* The elem should contain a 'fuse_in_header' (in to fuse) > > >>> * plus the data based on the len in the header. > > >>> @@ -555,11 +544,9 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > >>> ((struct fuse_in_header *)fbuf.mem)->opcode == > > >>> FUSE_READ && > > >>> out_sg[1].iov_len == sizeof(struct fuse_read_in)) { > > >>> - if (se->debug) { > > >>> - fuse_debug("Unmappable read case " > > >>> - "in_num=%d bad_in_num=%d\n", > > >>> - elem->in_num, req->bad_in_num); > > >>> - } > > >>> + fuse_debug("Unmappable read case " > > >>> + "in_num=%d bad_in_num=%d\n", > > >>> + elem->in_num, req->bad_in_num); > > >>> handled_unmappable = true; > > >>> } > > >>> > > >>> @@ -581,8 +568,7 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > >>> // data, we can just do it straight out of guest memory > > >>> // but we must sitll copy the headers in case the guest > > >>> // was nasty and changed them while we were using them. > > >>> - if (se->debug) > > >>> - fuse_debug("%s: Write special case\n", __func__); > > >>> + fuse_debug("%s: Write special case\n", __func__); > > >>> > > >>> // copy the fuse_write_in header afte rthe fuse_in_header > > >>> fbuf.mem += out_sg->iov_len; > > >>> @@ -636,10 +622,8 @@ static void fv_queue_worker(gpointer data, gpointer user_data) > > >>> if (!req->reply_sent) { > > >>> struct VuVirtq *q = vu_get_queue(dev, qi->qidx); > > >>> > > >>> - if (se->debug) { > > >>> - fuse_debug("%s: elem %d no reply sent\n", > > >>> - __func__, elem->index); > > >>> - } > > >>> + fuse_debug("%s: elem %d no reply sent\n", > > >>> + __func__, elem->index); > > >>> > > >>> pthread_rwlock_rdlock(&qi->virtio_dev->vu_dispatch_rwlock); > > >>> pthread_mutex_lock(&qi->vq_lock); > > >>> @@ -683,8 +667,7 @@ static void *fv_queue_thread(void *opaque) > > >>> pf[1].events = POLLIN; > > >>> pf[1].revents = 0; > > >>> > > >>> - if (qi->virtio_dev->se->debug) > > >>> - fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > > >>> + fuse_debug("%s: Waiting for Queue %d event\n", __func__, qi->qidx); > > >>> int poll_res = ppoll(pf, 2, NULL, NULL); > > >>> > > >>> if (poll_res == -1) { > > >>> @@ -712,9 +695,8 @@ static void *fv_queue_thread(void *opaque) > > >>> break; > > >>> } > > >>> assert(pf[0].revents & POLLIN); > > >>> - if (qi->virtio_dev->se->debug) > > >>> - fuse_debug("%s: Got queue event on Queue %d\n", > > >>> - __func__, qi->qidx); > > >>> + fuse_debug("%s: Got queue event on Queue %d\n", > > >>> + __func__, qi->qidx); > > >>> > > >>> eventfd_t evalue; > > >>> if (eventfd_read(qi->kick_fd, &evalue)) { > > >>> @@ -728,15 +710,13 @@ static void *fv_queue_thread(void *opaque) > > >>> > > >>> pthread_mutex_lock(&qi->vq_lock); > > >>> > > >>> - if (se->debug) { > > >>> - /* out is from guest, in is too guest */ > > >>> - unsigned int in_bytes, out_bytes; > > >>> - vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > > >>> + /* out is from guest, in is too guest */ > > >>> + unsigned int in_bytes, out_bytes; > > >>> + vu_queue_get_avail_bytes(dev, q, &in_bytes, &out_bytes, ~0, ~0); > > >>> > > >>> - fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > > >>> - __func__, qi->qidx, (size_t)evalue, in_bytes, > > >>> - out_bytes); > > >>> - } > > >>> + fuse_debug("%s: Queue %d gave evalue: %zx available: in: %u out: %u\n", > > >>> + __func__, qi->qidx, (size_t)evalue, in_bytes, > > >>> + out_bytes); > > >>> > > >>> while (1) { > > >>> unsigned int bad_in_num = 0, bad_out_num = 0; > > >>> @@ -871,8 +851,7 @@ int virtio_loop(struct fuse_session *se) > > >>> pf[0].events = POLLIN; > > >>> pf[0].revents = 0; > > >>> > > >>> - if (se->debug) > > >>> - fuse_debug("%s: Waiting for VU event\n", __func__); > > >>> + fuse_debug("%s: Waiting for VU event\n", __func__); > > >>> int poll_res = ppoll(pf, 1, NULL, NULL); > > >>> > > >>> if (poll_res == -1) { > > >>> @@ -890,8 +869,7 @@ int virtio_loop(struct fuse_session *se) > > >>> break; > > >>> } > > >>> assert(pf[0].revents & POLLIN); > > >>> - if (se->debug) > > >>> - fuse_debug("%s: Got VU event\n", __func__); > > >>> + fuse_debug("%s: Got VU event\n", __func__); > > >>> > > >>> /* Mutual exclusion with fv_queue_thread() */ > > >>> ret = pthread_rwlock_wrlock(&se->virtio_dev->vu_dispatch_rwlock); > > >>> @@ -1058,9 +1036,7 @@ ssize_t fuse_virtio_write(fuse_req_t req, > > >>> msg.flags[0] = VHOST_USER_FS_FLAG_MAP_W; > > >>> > > >>> int64_t result = fuse_virtio_io(req->se, &msg, dst->fd); > > >>> - if (req->se->debug) { > > >>> - fuse_debug("%s: result=%ld\n", __func__, result); > > >>> - } > > >>> + fuse_debug("%s: result=%ld\n", __func__, result); > > >>> return result; > > >>> } > > >>> > > >>> diff --git a/contrib/virtiofsd/helper.c b/contrib/virtiofsd/helper.c > > >>> index 5eae1f530aae..dc80100e8594 100644 > > >>> --- a/contrib/virtiofsd/helper.c > > >>> +++ b/contrib/virtiofsd/helper.c > > >>> @@ -27,6 +27,8 @@ > > >>> > > >>> #define FUSE_HELPER_OPT(t, p) \ > > >>> { t, offsetof(struct fuse_cmdline_opts, p), 1 } > > >>> +#define FUSE_HELPER_OPT_VALUE(t, p, v) \ > > >>> + { t, offsetof(struct fuse_cmdline_opts, p), v } > > >>> > > >>> static const struct fuse_opt fuse_helper_opts[] = { > > >>> FUSE_HELPER_OPT("-h", show_help), > > >>> @@ -50,6 +52,10 @@ static const struct fuse_opt fuse_helper_opts[] = { > > >>> FUSE_HELPER_OPT("clone_fd", clone_fd), > > >>> FUSE_HELPER_OPT("max_idle_threads=%u", max_idle_threads), > > >>> FUSE_HELPER_OPT("--syslog", syslog), > > >>> + FUSE_HELPER_OPT_VALUE("log_level=debug", log_level, LOG_DEBUG), > > >>> + FUSE_HELPER_OPT_VALUE("log_level=info", log_level, LOG_INFO), > > >>> + FUSE_HELPER_OPT_VALUE("log_level=warn", log_level, LOG_WARNING), > > >>> + FUSE_HELPER_OPT_VALUE("log_level=err", log_level, LOG_ERR), > > >>> FUSE_OPT_END > > >>> }; > > >>> > > >>> @@ -137,7 +143,9 @@ void fuse_cmdline_help(void) > > >>> " -o clone_fd use separate fuse device fd for each thread\n" > > >>> " (may improve performance)\n" > > >>> " -o max_idle_threads the maximum number of idle worker threads\n" > > >>> - " allowed (default: 10)\n"); > > >>> + " allowed (default: 10)\n" > > >>> + " -o log_level=<level> log level, default to \"info\"\n" > > >>> + " level could be one of \"debug, info, warn, err\"\n"); > > >>> } > > >>> > > >>> static int fuse_helper_opt_proc(void *data, const char *arg, int key, > > >>> diff --git a/contrib/virtiofsd/passthrough_ll.c b/contrib/virtiofsd/passthrough_ll.c > > >>> index 321bbb20be65..583e9685161f 100644 > > >>> --- a/contrib/virtiofsd/passthrough_ll.c > > >>> +++ b/contrib/virtiofsd/passthrough_ll.c > > >>> @@ -36,6 +36,7 @@ > > >>> > > >>> #include "fuse_virtio.h" > > >>> #include "fuse_lowlevel.h" > > >>> +#include "fuse_log.h" > > >>> #include <unistd.h> > > >>> #include <stdlib.h> > > >>> #include <stdio.h> > > >>> @@ -421,11 +422,6 @@ static int lo_fd(fuse_req_t req, fuse_ino_t ino) > > >>> return fd; > > >>> } > > >>> > > >>> -static bool lo_debug(fuse_req_t req) > > >>> -{ > > >>> - return lo_data(req)->debug != 0; > > >>> -} > > >>> - > > >>> static void lo_init(void *userdata, > > >>> struct fuse_conn_info *conn) > > >>> { > > >>> @@ -436,18 +432,15 @@ static void lo_init(void *userdata, > > >>> > > >>> if (lo->writeback && > > >>> conn->capable & FUSE_CAP_WRITEBACK_CACHE) { > > >>> - if (lo->debug) > > >>> - fuse_debug("lo_init: activating writeback\n"); > > >>> + fuse_debug("lo_init: activating writeback\n"); > > >>> conn->want |= FUSE_CAP_WRITEBACK_CACHE; > > >>> } > > >>> if (conn->capable & FUSE_CAP_FLOCK_LOCKS) { > > >>> if (lo->flock) { > > >>> - if (lo->debug) > > >>> - fuse_debug("lo_init: activating flock locks\n"); > > >>> + fuse_debug("lo_init: activating flock locks\n"); > > >>> conn->want |= FUSE_CAP_FLOCK_LOCKS; > > >>> } else { > > >>> - if (lo->debug) > > >>> - fuse_debug("lo_init: disabling flock locks\n"); > > >>> + fuse_debug("lo_init: disabling flock locks\n"); > > >>> conn->want &= ~FUSE_CAP_FLOCK_LOCKS; > > >>> } > > >>> } > > >>> @@ -455,20 +448,17 @@ static void lo_init(void *userdata, > > >>> > > >>> if (conn->capable & FUSE_CAP_POSIX_LOCKS) { > > >>> if (lo->posix_lock) { > > >>> - if (lo->debug) > > >>> - fuse_debug("lo_init: activating posix locks\n"); > > >>> + fuse_debug("lo_init: activating posix locks\n"); > > >>> conn->want |= FUSE_CAP_POSIX_LOCKS; > > >>> } else { > > >>> - if (lo->debug) > > >>> - fuse_debug("lo_init: disabling posix locks\n"); > > >>> + fuse_debug("lo_init: disabling posix locks\n"); > > >>> conn->want &= ~FUSE_CAP_POSIX_LOCKS; > > >>> } > > >>> } > > >>> > > >>> if ((lo->cache == CACHE_NONE && !lo->readdirplus_set) || > > >>> lo->readdirplus_clear || lo->shared) { > > >>> - if (lo->debug) > > >>> - fuse_debug("lo_init: disabling readdirplus\n"); > > >>> + fuse_debug("lo_init: disabling readdirplus\n"); > > >>> conn->want &= ~FUSE_CAP_READDIRPLUS; > > >>> } > > >>> } > > >>> @@ -909,12 +899,11 @@ static int lo_do_lookup(fuse_req_t req, fuse_ino_t parent, const char *name, > > >>> lo_inode_put(lo, &inode); > > >>> lo_inode_put(lo, &dir); > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > > >>> - (unsigned long long) parent, name, > > >>> - (unsigned long long) e->ino, > > >>> - (unsigned long long) e->version_offset, > > >>> - (unsigned long long) e->initial_version); > > >>> + fuse_debug(" %lli/%s -> %lli (version_table[%lli]=%lli)\n", > > >>> + (unsigned long long) parent, name, > > >>> + (unsigned long long) e->ino, > > >>> + (unsigned long long) e->version_offset, > > >>> + (unsigned long long) e->initial_version); > > >>> > > >>> return 0; > > >>> > > >>> @@ -932,9 +921,7 @@ static void lo_lookup(fuse_req_t req, fuse_ino_t parent, const char *name) > > >>> struct fuse_entry_param e; > > >>> int err; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", > > >>> - parent, name); > > >>> + fuse_debug("lo_lookup(parent=%" PRIu64 ", name=%s)\n", parent, name); > > >>> > > >>> /* Don't use is_safe_path_component(), allow "." and ".." for NFS export > > >>> * support. > > >>> @@ -1040,10 +1027,9 @@ static void lo_mknod_symlink(fuse_req_t req, fuse_ino_t parent, > > >>> if (saverr) > > >>> goto out; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug(" %lli/%s -> %lli\n", > > >>> - (unsigned long long) parent, name, > > >>> - (unsigned long long) e.ino); > > >>> + fuse_debug(" %lli/%s -> %lli\n", > > >>> + (unsigned long long) parent, name, > > >>> + (unsigned long long) e.ino); > > >>> > > >>> fuse_reply_entry(req, &e, lo->shared); > > >>> lo_inode_put(lo, &dir); > > >>> @@ -1149,10 +1135,9 @@ static void lo_link(fuse_req_t req, fuse_ino_t ino, fuse_ino_t parent, > > >>> update_version(lo, inode); > > >>> update_version(lo, parent_inode); > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug(" %lli/%s -> %lli\n", > > >>> - (unsigned long long) parent, name, > > >>> - (unsigned long long) e.ino); > > >>> + fuse_debug(" %lli/%s -> %lli\n", > > >>> + (unsigned long long) parent, name, > > >>> + (unsigned long long) e.ino); > > >>> > > >>> fuse_reply_entry(req, &e, lo->shared); > > >>> lo_inode_put(lo, &parent_inode); > > >>> @@ -1355,12 +1340,10 @@ static void lo_forget_one(fuse_req_t req, fuse_ino_t ino, uint64_t nlookup) > > >>> if (!inode) > > >>> return; > > >>> > > >>> - if (lo_debug(req)) { > > >>> - fuse_debug(" forget %lli %lli -%lli\n", > > >>> - (unsigned long long) ino, > > >>> - (unsigned long long) inode->nlookup, > > >>> - (unsigned long long) nlookup); > > >>> - } > > >>> + fuse_debug(" forget %lli %lli -%lli\n", > > >>> + (unsigned long long) ino, > > >>> + (unsigned long long) inode->nlookup, > > >>> + (unsigned long long) nlookup); > > >>> > > >>> unref_inode(lo, inode, nlookup); > > >>> lo_inode_put(lo, &inode); > > >>> @@ -1642,9 +1625,7 @@ static void lo_create(fuse_req_t req, fuse_ino_t parent, const char *name, > > >>> int err; > > >>> struct lo_cred old = {}; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", > > >>> - parent, name); > > >>> + fuse_debug("lo_create(parent=%" PRIu64 ", name=%s)\n", parent, name); > > >>> > > >>> if (!is_safe_path_component(name)) { > > >>> fuse_reply_err(req, EINVAL); > > >>> @@ -1744,11 +1725,10 @@ static void lo_getlk(fuse_req_t req, fuse_ino_t ino, > > >>> struct lo_inode_plock *plock; > > >>> int ret, saverr = 0; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > > >>> - " owner=0x%lx, l_type=%d l_start=0x%lx" > > >>> - " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > > >>> - lock->l_type, lock->l_start, lock->l_len); > > >>> + fuse_debug("lo_getlk(ino=%" PRIu64 ", flags=%d)" > > >>> + " owner=0x%lx, l_type=%d l_start=0x%lx" > > >>> + " l_len=0x%lx\n", ino, fi->flags, fi->lock_owner, > > >>> + lock->l_type, lock->l_start, lock->l_len); > > >>> > > >>> inode = lo_inode(req, ino); > > >>> if (!inode) { > > >>> @@ -1786,12 +1766,11 @@ static void lo_setlk(fuse_req_t req, fuse_ino_t ino, > > >>> struct lo_inode_plock *plock; > > >>> int ret, saverr = 0; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > > >>> - " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > > >>> - " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > > >>> - lock->l_type, lock->l_pid, fi->lock_owner, sleep, > > >>> - lock->l_whence, lock->l_start, lock->l_len); > > >>> + fuse_debug("lo_setlk(ino=%" PRIu64 ", flags=%d)" > > >>> + " cmd=%d pid=%d owner=0x%lx sleep=%d l_whence=%d" > > >>> + " l_start=0x%lx l_len=0x%lx\n", ino, fi->flags, > > >>> + lock->l_type, lock->l_pid, fi->lock_owner, sleep, > > >>> + lock->l_whence, lock->l_start, lock->l_len); > > >>> > > >>> if (sleep) { > > >>> fuse_reply_err(req, EOPNOTSUPP); > > >>> @@ -1860,9 +1839,7 @@ static void lo_open(fuse_req_t req, fuse_ino_t ino, struct fuse_file_info *fi) > > >>> char buf[64]; > > >>> struct lo_data *lo = lo_data(req); > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", > > >>> - ino, fi->flags); > > >>> + fuse_debug("lo_open(ino=%" PRIu64 ", flags=%d)\n", ino, fi->flags); > > >>> > > >>> /* With writeback cache, kernel may send read requests even > > >>> when userspace opened write-only */ > > >>> @@ -1965,9 +1942,7 @@ static void lo_fsync(fuse_req_t req, fuse_ino_t ino, int datasync, > > >>> int fd; > > >>> char *buf; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, > > >>> - (void *)fi); > > >>> + fuse_debug("lo_fsync(ino=%" PRIu64 ", fi=0x%p)\n", ino, (void *)fi); > > >>> > > >>> if (!fi) { > > >>> res = asprintf(&buf, "%i", lo_fd(req, ino)); > > >>> @@ -1995,9 +1970,8 @@ static void lo_read(fuse_req_t req, fuse_ino_t ino, size_t size, > > >>> { > > >>> struct fuse_bufvec buf = FUSE_BUFVEC_INIT(size); > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > > >>> - "off=%lu)\n", ino, size, (unsigned long) offset); > > >>> + fuse_debug("lo_read(ino=%" PRIu64 ", size=%zd, " > > >>> + "off=%lu)\n", ino, size, (unsigned long) offset); > > >>> > > >>> buf.buf[0].flags = FUSE_BUF_IS_FD | FUSE_BUF_FD_SEEK; > > >>> buf.buf[0].fd = lo_fi_fd(req, fi); > > >>> @@ -2019,9 +1993,8 @@ static void lo_write_buf(fuse_req_t req, fuse_ino_t ino, > > >>> out_buf.buf[0].fd = lo_fi_fd(req, fi); > > >>> out_buf.buf[0].pos = off; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > > >>> - ino, out_buf.buf[0].size, (unsigned long) off); > > >>> + fuse_debug("lo_write_buf(ino=%" PRIu64 ", size=%zd, off=%lu)\n", > > >>> + ino, out_buf.buf[0].size, (unsigned long) off); > > >>> > > >>> res = fuse_buf_copy(req, &out_buf, in_buf, 0); > > >>> if(res < 0) { > > >>> @@ -2105,10 +2078,8 @@ static void lo_getxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > > >>> if (!lo_data(req)->xattr) > > >>> goto out; > > >>> > > >>> - if (lo_debug(req)) { > > >>> - fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > > >>> - ino, name, size); > > >>> - } > > >>> + fuse_debug("lo_getxattr(ino=%" PRIu64 ", name=%s size=%zd)\n", > > >>> + ino, name, size); > > >>> > > >>> if (inode->is_symlink) { > > >>> /* Sorry, no race free way to getxattr on symlink. */ > > >>> @@ -2180,10 +2151,7 @@ static void lo_listxattr(fuse_req_t req, fuse_ino_t ino, size_t size) > > >>> if (!lo_data(req)->xattr) > > >>> goto out; > > >>> > > >>> - if (lo_debug(req)) { > > >>> - fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", > > >>> - ino, size); > > >>> - } > > >>> + fuse_debug("lo_listxattr(ino=%" PRIu64 ", size=%zd)\n", ino, size); > > >>> > > >>> if (inode->is_symlink) { > > >>> /* Sorry, no race free way to listxattr on symlink. */ > > >>> @@ -2255,10 +2223,8 @@ static void lo_setxattr(fuse_req_t req, fuse_ino_t ino, const char *name, > > >>> if (!lo_data(req)->xattr) > > >>> goto out; > > >>> > > >>> - if (lo_debug(req)) { > > >>> - fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > > >>> - ino, name, value, size); > > >>> - } > > >>> + fuse_debug("lo_setxattr(ino=%" PRIu64 ", name=%s value=%s size=%zd)\n", > > >>> + ino, name, value, size); > > >>> > > >>> if (inode->is_symlink) { > > >>> /* Sorry, no race free way to removexattr on symlink. */ > > >>> @@ -2306,10 +2272,7 @@ static void lo_removexattr(fuse_req_t req, fuse_ino_t ino, const char *name) > > >>> if (!lo_data(req)->xattr) > > >>> goto out; > > >>> > > >>> - if (lo_debug(req)) { > > >>> - fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", > > >>> - ino, name); > > >>> - } > > >>> + fuse_debug("lo_removexattr(ino=%" PRIu64 ", name=%s)\n", ino, name); > > >>> > > >>> if (inode->is_symlink) { > > >>> /* Sorry, no race free way to setxattr on symlink. */ > > >>> @@ -2351,12 +2314,11 @@ static void lo_copy_file_range(fuse_req_t req, fuse_ino_t ino_in, off_t off_in, > > >>> in_fd = lo_fi_fd(req, fi_in); > > >>> out_fd = lo_fi_fd(req, fi_out); > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > > >>> - "off=%lu, ino=%" PRIu64 "/fd=%d, " > > >>> - "off=%lu, size=%zd, flags=0x%x)\n", > > >>> - ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > > >>> - flags); > > >>> + fuse_debug("lo_copy_file_range(ino=%" PRIu64 "/fd=%d, " > > >>> + "off=%lu, ino=%" PRIu64 "/fd=%d, " > > >>> + "off=%lu, size=%zd, flags=0x%x)\n", > > >>> + ino_in, in_fd, off_in, ino_out, out_fd, off_out, len, > > >>> + flags); > > >>> > > >>> res = copy_file_range(in_fd, &off_in, out_fd, &off_out, len, flags); > > >>> if (res < 0) > > >>> @@ -2377,11 +2339,10 @@ static void lo_setupmapping(fuse_req_t req, fuse_ino_t ino, uint64_t foffset, > > >>> char *buf; > > >>> bool writable = flags & O_RDWR; > > >>> > > >>> - if (lo_debug(req)) > > >>> - fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > > >>> - " foffset=%" PRIu64 ", len=%" PRIu64 > > >>> - ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > > >>> - (void *)fi, foffset, len, moffset, flags); > > >>> + fuse_debug("lo_setupmapping(ino=%" PRIu64 ", fi=0x%p," > > >>> + " foffset=%" PRIu64 ", len=%" PRIu64 > > >>> + ", moffset=%" PRIu64 ", flags=%" PRIu64 ")\n", ino, > > >>> + (void *)fi, foffset, len, moffset, flags); > > >>> > > >>> vhu_flags = VHOST_USER_FS_FLAG_MAP_R; > > >>> if (writable) > > >>> @@ -2878,7 +2839,16 @@ int main(int argc, char *argv[]) > > >>> if (fuse_opt_parse(&args, &lo, lo_opts, NULL)== -1) > > >>> goto err_out1; > > >>> > > >>> + /* > > >>> + * log_level is 0 if not configured via cmd options (0 is LOG_EMERG, > > >>> + * and we don't use this log level). > > >>> + */ > > >>> + if (opts.log_level != 0) > > >>> + current_log_level = opts.log_level; > > >>> lo.debug = opts.debug; > > >>> + if (lo.debug) > > >>> + current_log_level = LOG_DEBUG; > > >>> + > > >>> if (lo.source) { > > >>> struct stat stat; > > >>> int res; > > >>> > > >> > > >> _______________________________________________ > > >> Virtio-fs mailing list > > >> Virtio-fs@redhat.com > > >> https://www.redhat.com/mailman/listinfo/virtio-fs > > > . > > > > > _______________________________________________ > Virtio-fs mailing list > Virtio-fs@redhat.com > https://www.redhat.com/mailman/listinfo/virtio-fs -- Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK ^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2019-08-16 16:52 UTC | newest] Thread overview: 12+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2019-08-09 8:25 [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough Eryu Guan 2019-08-09 8:25 ` [Virtio-fs] [PATCH 2/2] virtiofsd: convert more fprintf and perror to use fuse log infra Eryu Guan 2019-08-09 9:40 ` piaojun 2019-08-11 13:21 ` Eryu Guan 2019-08-11 14:12 ` piaojun 2019-08-16 16:52 ` Dr. David Alan Gilbert 2019-08-09 9:34 ` [Virtio-fs] [PATCH 1/2] virtiofsd: print log only when priority is high enough piaojun 2019-08-11 13:20 ` Eryu Guan 2019-08-11 14:32 ` piaojun 2019-08-11 15:35 ` Eryu Guan 2019-08-12 2:28 ` piaojun 2019-08-15 9:45 ` Dr. David Alan Gilbert
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.