kio_pcs: Compact the logs and make eyes happy

Submitted by Kirill Korotaev on Dec. 5, 2018, 11:02 a.m.

Details

Message ID 54CFF272-D54E-44C9-9259-C287E6A46835@acronis.com
State New
Series "kio_pcs: Compact the logs and make eyes happy"
Headers show

Commit Message

Kirill Korotaev Dec. 5, 2018, 11:02 a.m.
Guys, JFYI, we are getting rid of LOG_NONL and indent in logger as non multi-thread safe (we are moving towards multi threaded eventloop):
https://git.acronis.com/projects/STRG/repos/pstorage-core/pull-requests/765/diff


On 5 Dec 2018, at 12:29, Pavel Butsykin <pbutsykin@virtuozzo.com<mailto:pbutsykin@virtuozzo.com>> wrote:

On 04.12.2018 23:13, Pavel Emelianov wrote:
On 12/04/2018 10:28 PM, Pavel Emelyanov wrote:
On 12/03/2018 05:20 PM, Pavel Butsykin wrote:
On 30.11.2018 19:44, Pavel Emelianov wrote:
On 11/30/2018 05:57 PM, Pavel Butsykin wrote:
Hmm, __kfuse_trace() duplicates message to debugfs trace, without '\n'

Yes, and AFAIS most of the existing messages already come w/o it.

More likely logs without '\n' are present mainly for error cases,
perhaps this is why it wasn't noticed before. But yes, we have a mess
with logs.

I propose to fix all FUSE_K* traces with '\n' and use
trace_printk("%s\n") for duplicating messages to debugsfs. But
duplicating messages to debugfs should be turned off by default (with
the ability to enable via sysfs), because write messages to debugfs
without user's permission.. it's looks a little impolite :)

The issue is not in duplicating messages, but in \n creeping into
user-space logs. But anyway, OK, equipping them all with \n-s sounds
OK to me.

Not any more. Please, look at this PR: https://git.acronis.com/projects/STRG/repos/pstorage-core/pull-requests/765
The proposal is to drop the LOG_NONL thing from textual logs. If done, then
messages coming with \n at the end will have double \n-s in text logs.

Actually, we don't need to worry about merged messages in debugs,
because __trace_puts() adds \n if it necessary:
int __trace_puts(unsigned long ip, const char *str, int size)
...
/* Add a newline if necessary */
if (entry->buf[size - 1] != '\n') {
entry->buf[size] = '\n';
entry->buf[size + 1] = '\0';
} else
entry->buf[size] = '\0';

I missed it in the beginning, sorry for that.

Along with this, we can allow drop LOG_NONL options from usermode and
this patch is OK for me, except for a small correction:
void __kfuse_trace(struct fuse_conn * fc, unsigned long ip, const char *
fmt, ...)
...
- pr_debug("%s", buf);
+ pr_debug("%s\n", buf);

this messages will look weird. We need to fix __kfuse_trace() by adding
concatenation '\n' (or even drop duplication messages to debugsfs/dmesg,
as not a very useful thing).

On 30.11.2018 17:35, Pavel Butsykin wrote:
Would you like to fix all FUSE_KTRACE's in the kernel? I see a few more
FUSE_KTRACE with '\n'.

On 30.11.2018 17:23, Pavel Emelianov wrote:
After a recent (b)log (re)work it was noticed that some extra \n-s crept
into the classical log files. Indeed, the pstorage TRACE() call appends a
\n at the end of each message and so does the kernel code.

Sorry for inconvenience.

https://pmc.acronis.com/browse/VSTOR-18383

Signed-off-by: Pavel Emelyanov <xemul@virtuozzo.com>

---

Patch hide | download patch | download mbox

diff --git a/fs/fuse/kio/pcs/pcs_map.c b/fs/fuse/kio/pcs/pcs_map.c
index 4596454..34fa88c 100644
--- a/fs/fuse/kio/pcs/pcs_map.c
+++ b/fs/fuse/kio/pcs/pcs_map.c
@@ -1946,7 +1946,7 @@  static int pcs_cslist_submit_read(struct pcs_int_request *ireq, struct pcs_cs_li
     WRITE_ONCE(csl->read_index, i);
     WRITE_ONCE(csl->select_stamp, jiffies);

- FUSE_KTRACE(ireq->cc->fc, "Selected read map " MAP_FMT " to CS" NODE_FMT "; is_seq=%d\n", MAP_ARGS(ireq->iochunk.map),
+ FUSE_KTRACE(ireq->cc->fc, "Selected read map " MAP_FMT " to CS" NODE_FMT "; is_seq=%d", MAP_ARGS(ireq->iochunk.map),
          NODE_ARGS(csl->cs[i].cslink.cs->id), is_seq);
     pcs_flow_bind_cs(ireq->iochunk.flow, csl->cs[i].cslink.cs);
     }