* [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 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 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 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 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 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
* 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
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.