On Mon, Feb 03, 2025 at 07:10:25AM +0100, Stefano Brivio wrote:On Mon, 3 Feb 2025 14:11:10 +1100 David Gibson <david(a)gibson.dropbear.id.au> wrote:Eh, I mean it's like 4ish events per migration. And they are actually related to the migration, rather than being unrelated async noise like the stuff in vu_kick_cb(). Admittedly they are pretty verbose messages.On Fri, Jan 31, 2025 at 08:39:49PM +0100, Stefano Brivio wrote:Well, "rare" is relative, if you're debugging state migration transfers. :) But...Having every vhost-user message printed as part of debug output makes debugging anything else a bit complicated. Signed-off-by: Stefano Brivio <sbrivio(a)redhat.com>I'm a little bit baffled by this. You're changing to trace() a couple of relatively rare messagesYeah, I'd be fine with making those vhost-user messages a little bit less individually noisy. Which presumably they were to make those stand out against the other debug messages. We perhaps don't want to get into a shouting war with ourselves.that I think belong in debug() category,actually, yes, they're not so frequent. Probably we should improve on the reporting instead, because good luck finding your little message with transferred sizes in a rain of: ================ Vhost user message ================ we probably need a simple facility in vhost-user code allowing to start and continue some messages, so that if we need two lines here for "vhost-user: req %s (%d)\nflags: ..." we can do that easily.As long as we're single-threaded, by the way, this could be simply two calls to debug().-- David Gibson (he or they) | I'll have my music baroque, and my code david AT gibson.dropbear.id.au | minimalist, thank you, not the other way | around. http://www.ozlabs.org/~dgibsonbut *not* changing some things that definitely should be trace() - such as the ones in vu_send_single() and vu_kick_cb().Right, also noted for follow-ups.> --- > vhost_user.c | 12 ++++++------ > 1 file changed, 6 insertions(+), 6 deletions(-) > > diff --git a/vhost_user.c b/vhost_user.c > index 2dde405..1092387 100644 > --- a/vhost_user.c > +++ b/vhost_user.c > @@ -640,8 +640,8 @@ static bool vu_set_vring_num_exec(struct vu_dev *vdev, > unsigned int idx = msg->payload.state.index; > unsigned int num = msg->payload.state.num; > > - debug("State.index: %u", idx); > - debug("State.num: %u", num); > + trace("State.index: %u", idx); > + trace("State.num: %u", num); > vdev->vq[idx].vring.num = num; > > return false; > @@ -1176,11 +1176,11 @@ void vu_control_handler(struct vu_dev *vdev, int fd, uint32_t events) > vu_sock_reset(vdev); > return; > } > - debug("================ Vhost user message ================"); > - debug("Request: %s (%d)", vu_request_to_string(msg.hdr.request), > + trace("================ Vhost user message ================"); > + trace("Request: %s (%d)", vu_request_to_string(msg.hdr.request), > msg.hdr.request); > - debug("Flags: 0x%x", msg.hdr.flags); > - debug("Size: %u", msg.hdr.size); > + trace("Flags: 0x%x", msg.hdr.flags); > + trace("Size: %u", msg.hdr.size); > > need_reply = msg.hdr.flags & VHOST_USER_NEED_REPLY_MASK;