Re: [PATCH next v2 1/3] printk: inline log_output(),log_store() in vprintk_store()

[Petr Mladek]

On Thu 2020-12-03 17:31:29, John Ogness wrote:
> On 2020-12-03, Petr Mladek <pmladek@xxxxxxxx> wrote:
> >> +	if (lflags & LOG_CONT) {
> >> +		prb_rec_init_wr(&r, text_len);
> >> +		if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) {
> >> +			memcpy(&r.text_buf[r.info->text_len], text, text_len);
> >> +			r.info->text_len += text_len;
> >> +
> >> +			if (lflags & LOG_NEWLINE) {
> >> +				r.info->flags |= LOG_NEWLINE;
> >> +				prb_final_commit(&e);
> >> +			} else {
> >> +				prb_commit(&e);
> >> +			}
> >> +
> >> +			return text_len;
> >> +		}
> >> +	}
> >> +
> >> +	prb_rec_init_wr(&r, text_len);
> >
> > This is called in both branches. I would do it just once at the
> > beginning.
> 
> Actually that leads to a crash when prb_reserve_in_last() fails and the
> fallback code uses a record that prb_reserve_in_last() has already
> touched. The implementation of prb_reserve_in_last() would have to be
> changed so that failure guarantees that @r has not been
> modified. Currently prb_reserve_in_last() can fail after modifying @r.

I see. It would deserve a comment so that nobody repeats my mistake
again. I am sure that I would be able to do it once again few
months from now ;-)

> >> +	if (!prb_reserve(&e, prb, &r)) {
> >> +		/* truncate the message if it is too long for empty buffer */
> >> +		truncate_msg(&text_len, &trunc_msg_len);
> >> +
> >> +		prb_rec_init_wr(&r, text_len + trunc_msg_len);
> >> +		if (!prb_reserve(&e, prb, &r))
> >> +			return 0;
> >> +	}
> >> +
> >> +	/* fill message */
> >> +	memcpy(&r.text_buf[0], text, text_len);
> >> +	if (trunc_msg_len)
> >> +		memcpy(&r.text_buf[text_len], trunc_msg, trunc_msg_len);
> >> +	r.info->text_len = text_len + trunc_msg_len;
> >> +	r.info->facility = facility;
> >> +	r.info->level = level & 7;
> >> +	r.info->flags = lflags & 0x1f;
> >> +	r.info->ts_nsec = ts_nsec;
> >
> > This is the only location where ts_nsec is used. I would remove the
> > variable and call:
> >
> > 	r.info->ts_nsec = local_clock();
> 
> My reason for grabbing the clock at the beginning is so that the
> timestamp is as close to the printk() call as possible. IMHO it is a
> more deterministic timestamp than if it is taken after reservation(s)
> and sprint'ing. I prefer to keep it as it is, but will not object if
> such a change is necessary for mailine acceptance.

Fair enough. It would deserve a comment as well.

Best Regards,
Petr