While the tracing frawework does not forbid trailing newline in
events format string, using them lead to confuse output.
It is the responsibility of the backend to properly end an event
line.

Some of our formats have trailing newlines, remove them.

Reviewed-by: John Snow <jsnow@redhat.com>
Reviewed-by: Kevin Wolf <kwolf@redhat.com>
Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com>
---
 hw/misc/trace-events | 10 +++++-----
 hw/scsi/trace-events |  2 +-
 hw/sd/trace-events   |  2 +-
 nbd/trace-events     |  4 ++--
 net/trace-events     |  6 +++---
 5 files changed, 12 insertions(+), 12 deletions(-)

diff --git a/hw/misc/trace-events b/hw/misc/trace-events
index c1ea1aa437..74276225f8 100644
--- a/hw/misc/trace-events
+++ b/hw/misc/trace-events
@@ -118,11 +118,11 @@ iotkit_secctl_ns_read(uint32_t offset, uint64_t data, unsigned size) "IoTKit Sec
 iotkit_secctl_ns_write(uint32_t offset, uint64_t data, unsigned size) "IoTKit SecCtl NS regs write: offset 0x%x data 0x%" PRIx64 " size %u"
 
 # imx6ul_ccm.c
-ccm_entry(void) "\n"
-ccm_freq(uint32_t freq) "freq = %d\n"
-ccm_clock_freq(uint32_t clock, uint32_t freq) "(Clock = %d) = %d\n"
-ccm_read_reg(const char *reg_name, uint32_t value) "reg[%s] <= 0x%" PRIx32 "\n"
-ccm_write_reg(const char *reg_name, uint32_t value) "reg[%s] => 0x%" PRIx32 "\n"
+ccm_entry(void) ""
+ccm_freq(uint32_t freq) "freq = %d"
+ccm_clock_freq(uint32_t clock, uint32_t freq) "(Clock = %d) = %d"
+ccm_read_reg(const char *reg_name, uint32_t value) "reg[%s] <= 0x%" PRIx32
+ccm_write_reg(const char *reg_name, uint32_t value) "reg[%s] => 0x%" PRIx32
 
 # iotkit-sysinfo.c
 iotkit_sysinfo_read(uint64_t offset, uint64_t data, unsigned size) "IoTKit SysInfo read: offset 0x%" PRIx64 " data 0x%" PRIx64 " size %u"
diff --git a/hw/scsi/trace-events b/hw/scsi/trace-events
index 452b5994e6..b0820052f8 100644
--- a/hw/scsi/trace-events
+++ b/hw/scsi/trace-events
@@ -28,7 +28,7 @@ mptsas_mmio_read(void *dev, uint32_t addr, uint32_t val) "dev %p addr 0x%08x val
 mptsas_mmio_unhandled_read(void *dev, uint32_t addr) "dev %p addr 0x%08x"
 mptsas_mmio_unhandled_write(void *dev, uint32_t addr, uint32_t val) "dev %p addr 0x%08x value 0x%x"
 mptsas_mmio_write(void *dev, uint32_t addr, uint32_t val) "dev %p addr 0x%08x value 0x%x"
-mptsas_process_message(void *dev, int msg, uint32_t ctx) "dev %p cmd %d context 0x%08x\n"
+mptsas_process_message(void *dev, int msg, uint32_t ctx) "dev %p cmd %d context 0x%08x"
 mptsas_process_scsi_io_request(void *dev, int bus, int target, int lun, uint64_t len) "dev %p dev %d:%d:%d length %"PRIu64""
 mptsas_reset(void *dev) "dev %p "
 mptsas_scsi_overflow(void *dev, uint32_t ctx, uint64_t req, uint64_t found) "dev %p context 0x%08x: %"PRIu64"/%"PRIu64""
diff --git a/hw/sd/trace-events b/hw/sd/trace-events
index 52971dc033..efcff666a2 100644
--- a/hw/sd/trace-events
+++ b/hw/sd/trace-events
@@ -4,7 +4,7 @@
 bcm2835_sdhost_read(uint64_t offset, uint64_t data, unsigned size) "offset 0x%" PRIx64 " data 0x%" PRIx64 " size %u"
 bcm2835_sdhost_write(uint64_t offset, uint64_t data, unsigned size) "offset 0x%" PRIx64 " data 0x%" PRIx64 " size %u"
 bcm2835_sdhost_edm_change(const char *why, uint32_t edm) "(%s) EDM now 0x%x"
-bcm2835_sdhost_update_irq(uint32_t irq) "IRQ bits 0x%x\n"
+bcm2835_sdhost_update_irq(uint32_t irq) "IRQ bits 0x%x"
 
 # core.c
 sdbus_command(const char *bus_name, uint8_t cmd, uint32_t arg) "@%s CMD%02d arg 0x%08x"
diff --git a/nbd/trace-events b/nbd/trace-events
index f6cde96790..a955918e97 100644
--- a/nbd/trace-events
+++ b/nbd/trace-events
@@ -61,8 +61,8 @@ nbd_negotiate_begin(void) "Beginning negotiation"
 nbd_negotiate_new_style_size_flags(uint64_t size, unsigned flags) "advertising size %" PRIu64 " and flags 0x%x"
 nbd_negotiate_success(void) "Negotiation succeeded"
 nbd_receive_request(uint32_t magic, uint16_t flags, uint16_t type, uint64_t from, uint32_t len) "Got request: { magic = 0x%" PRIx32 ", .flags = 0x%" PRIx16 ", .type = 0x%" PRIx16 ", from = %" PRIu64 ", len = %" PRIu32 " }"
-nbd_blk_aio_attached(const char *name, void *ctx) "Export %s: Attaching clients to AIO context %p\n"
-nbd_blk_aio_detach(const char *name, void *ctx) "Export %s: Detaching clients from AIO context %p\n"
+nbd_blk_aio_attached(const char *name, void *ctx) "Export %s: Attaching clients to AIO context %p"
+nbd_blk_aio_detach(const char *name, void *ctx) "Export %s: Detaching clients from AIO context %p"
 nbd_co_send_simple_reply(uint64_t handle, uint32_t error, const char *errname, int len) "Send simple reply: handle = %" PRIu64 ", error = %" PRIu32 " (%s), len = %d"
 nbd_co_send_structured_done(uint64_t handle) "Send structured reply done: handle = %" PRIu64
 nbd_co_send_structured_read(uint64_t handle, uint64_t offset, void *data, size_t size) "Send structured read data reply: handle = %" PRIu64 ", offset = %" PRIu64 ", data = %p, len = %zu"
diff --git a/net/trace-events b/net/trace-events
index ac57056497..02c13fd0ba 100644
--- a/net/trace-events
+++ b/net/trace-events
@@ -17,9 +17,9 @@ colo_compare_icmp_miscompare(const char *sta, int size) ": %s = %d"
 colo_compare_ip_info(int psize, const char *sta, const char *stb, int ssize, const char *stc, const char *std) "ppkt size = %d, ip_src = %s, ip_dst = %s, spkt size = %d, ip_src = %s, ip_dst = %s"
 colo_old_packet_check_found(int64_t old_time) "%" PRId64
 colo_compare_miscompare(void) ""
-colo_compare_tcp_info(const char *pkt, uint32_t seq, uint32_t ack, int hdlen, int pdlen, int offset, int flags) "%s: seq/ack= %u/%u hdlen= %d pdlen= %d offset= %d flags=%d\n"
+colo_compare_tcp_info(const char *pkt, uint32_t seq, uint32_t ack, int hdlen, int pdlen, int offset, int flags) "%s: seq/ack= %u/%u hdlen= %d pdlen= %d offset= %d flags=%d"
 
 # filter-rewriter.c
 colo_filter_rewriter_debug(void) ""
-colo_filter_rewriter_pkt_info(const char *func, const char *src, const char *dst, uint32_t seq, uint32_t ack, uint32_t flag) "%s: src/dst: %s/%s p: seq/ack=%u/%u  flags=0x%x\n"
-colo_filter_rewriter_conn_offset(uint32_t offset) ": offset=%u\n"
+colo_filter_rewriter_pkt_info(const char *func, const char *src, const char *dst, uint32_t seq, uint32_t ack, uint32_t flag) "%s: src/dst: %s/%s p: seq/ack=%u/%u  flags=0x%x"
+colo_filter_rewriter_conn_offset(uint32_t offset) ": offset=%u"
-- 
2.20.1

On 9/16/19 4:51 AM, Philippe Mathieu-Daudé wrote:
> While the tracing frawework does not forbid trailing newline in

framework

> events format string, using them lead to confuse output.
> It is the responsibility of the backend to properly end an event
> line.

Why just trailing newline? Should we not forbid ALL use of newline in a
trace message?

> 
> Some of our formats have trailing newlines, remove them.
> 
> Reviewed-by: John Snow <jsnow@redhat.com>
> Reviewed-by: Kevin Wolf <kwolf@redhat.com>
> Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com>
> ---


-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3226
Virtualization:  qemu.org | libvirt.org

On 9/16/19 6:36 PM, Eric Blake wrote:
> On 9/16/19 4:51 AM, Philippe Mathieu-Daudé wrote:
>> While the tracing frawework does not forbid trailing newline in
> 
> framework
> 
>> events format string, using them lead to confuse output.
>> It is the responsibility of the backend to properly end an event
>> line.
> 
> Why just trailing newline? Should we not forbid ALL use of newline in a
> trace message?

I thought about it and forgot to add a comment when respining.
Yes, I think this is the right thing to enforce.
However it requires more cleanup, affecting more subsystems, so I'd
rather keep it for a follow-up series.

>>
>> Some of our formats have trailing newlines, remove them.
>>
>> Reviewed-by: John Snow <jsnow@redhat.com>
>> Reviewed-by: Kevin Wolf <kwolf@redhat.com>
>> Signed-off-by: Philippe Mathieu-Daudé <philmd@redhat.com>
>> ---

On 9/16/19 12:40 PM, Philippe Mathieu-Daudé wrote:
> On 9/16/19 6:36 PM, Eric Blake wrote:
>> On 9/16/19 4:51 AM, Philippe Mathieu-Daudé wrote:
>>> While the tracing frawework does not forbid trailing newline in
>>
>> framework
>>
>>> events format string, using them lead to confuse output.
>>> It is the responsibility of the backend to properly end an event
>>> line.
>>
>> Why just trailing newline? Should we not forbid ALL use of newline in a
>> trace message?
> 
> I thought about it and forgot to add a comment when respining.
> Yes, I think this is the right thing to enforce.
> However it requires more cleanup, affecting more subsystems, so I'd
> rather keep it for a follow-up series.

What's the problem with using multi-line trace statements?
Does it interfere with non-printf backends?

(I think I intentionally use these for AHCI in a few places.)

--js

On Mon, Sep 16, 2019 at 12:41:44PM -0400, John Snow wrote:
> On 9/16/19 12:40 PM, Philippe Mathieu-Daudé wrote:
> > On 9/16/19 6:36 PM, Eric Blake wrote:
> >> On 9/16/19 4:51 AM, Philippe Mathieu-Daudé wrote:
> >>> While the tracing frawework does not forbid trailing newline in
> >>
> >> framework
> >>
> >>> events format string, using them lead to confuse output.
> >>> It is the responsibility of the backend to properly end an event
> >>> line.
> >>
> >> Why just trailing newline? Should we not forbid ALL use of newline in a
> >> trace message?
> > 
> > I thought about it and forgot to add a comment when respining.
> > Yes, I think this is the right thing to enforce.
> > However it requires more cleanup, affecting more subsystems, so I'd
> > rather keep it for a follow-up series.
> 
> What's the problem with using multi-line trace statements?

I agree with avoiding trailing newlines in format strings in the
./trace-events files for consistency.

Although non-trailing newlines in format strings are unusual, they could
make trace logs easier to read in complex cases.  I don't see a reason
to forbid them since we support trace backends that emit a binary log
with a parsing API - there's no need to write scripts that parse the
text output.

> (I think I intentionally use these for AHCI in a few places.)

hw/ide/ahci.c format strings do not contain newlines, so they are
technically in compliance.

ahci_pretty_buffer_fis() is used to generate a hex dump with newlines
but it's a %s format string argument to trace_handle_reg_h2d_fis_dump()
and trace_handle_cmd_fis_dump().

Stefan