[Devel] [PATCH hci-8.1 4/6] ve/printk: Fix time virtualization

[no-reply at sashiko.virtuozzo.com]

Thank you for your contribution! Sashiko AI review found 4 potential issue(s) to consider:
- [Medium] printk: ve_log_printk() path stamps records with zero or stale time_offset
- [Medium] printk: unsynchronized log_state->time_offset used to pass author offsets
- [Medium] printk: time_namespace get/put in update_log_time() on atomic printk paths
- [Low] printk: 32-byte timens_offsets embedded in every printk_info grows ringbuffers and vmcoreinfo
--

commit eea8f8e8aad7cad7bcb35ee878f7d51794c27e83
Author: Vladimir Riabchun <vladimir.riabchun at virtuozzo.com>

ve/printk: Fix time virtualization

This patch stores timens offsets in each printk_info record, so the
timestamp is shifted using the offsets of the context that emitted the
message. The offsets are copied into log_state on each log_state lookup
and then into the record in vprintk_store_log().

Link: https://virtuozzo.atlassian.net/browse/VSTOR-146839

> diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h

[ ... ]

> @@ -354,11 +355,16 @@ struct log_state {
>  	 */
>  	struct latched_seq clear_seq;
>  	struct printk_ringbuffer *prb;
> +	/* Updated on every log_state request */
> +	struct timens_offsets time_offset;
>  };

[Severity: Medium]
Can passing the author offsets through shared log_state storage produce
torn or stale values?

update_log_time() does a plain multi-word struct copy into
GET_VE_LOG(ve)->time_offset on every ve_log_state() or __ve_log_state()
call. That includes read-only callers such as devkmsg_poll(),
devkmsg_read() and do_syslog(), and they can run concurrently on other
CPUs or in IRQ context.

vprintk_store_log() later reads the field with another plain copy, after
vsnprintf and prb_reserve. Nothing orders the two accesses, since there
is no lock, no seqcount and no READ_ONCE()/WRITE_ONCE().

The offsets are normally the same for a given VE. They can differ across a
VE stop and start, which the commit message says can produce a new time
namespace. In that case a mixed or stale value could be stored in the
ring buffer, and KCSAN would likely flag the race.

Would it be possible to compute the offsets locally in the writer and
pass them down to vprintk_emit_log() by value or by pointer?

> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -556,13 +556,28 @@ DEFINE_STRUCT_MEMBER_ALIAS(clear_seq, init_log_state, clear_seq);
>  DEFINE_STRUCT_MEMBER_ALIAS(prb, init_log_state, prb);
>  #undef DEFINE_STRUCT_MEMBER_ALIAS
>  
> +static void update_log_time(struct ve_struct *ve)
> +{
> +	struct time_namespace *timens = ve_get_time_ns(ve);
> +
> +	if (timens)
> +		GET_VE_LOG(ve)->time_offset = timens->offsets;
> +	else
> +		GET_VE_LOG(ve)->time_offset = init_time_ns.offsets;
> +
> +	if (timens)
> +		put_time_ns(timens);
> +}

[Severity: Medium]
Can the get/put pair here run from atomic context?

__ve_vprintk_emit() calls __ve_log_state(ve), which has no in_task()
guard, so it can be reached from IRQ or other atomic context:

__ve_vprintk_emit()
  __ve_log_state()
    update_log_time()
      ve_get_time_ns()
      put_time_ns()

If VE teardown clears ve_nsproxy and drops its reference between the get
and the put, the put_time_ns() here would be the last one. free_time_ns()
would then run from atomic or scheduler-locked printk context. I could not
confirm that this race is reachable, so this part is speculative.

Is the reference needed at all? An rcu_read_lock() section that copies the
offsets looks like it would be enough. The old code only took the reference
when formatting output, whereas now every log_state lookup pays for the
refcount inc/dec and the struct copy, including the read-only syslog and
devkmsg paths.

>  struct log_state *ve_log_state(void)
>  {
>  	struct log_state *log = &init_log_state;
>  #ifdef CONFIG_VE
>  	/* get_exec_env() is reliable only in task context */
> -	if (!WARN_ON_ONCE(!in_task()) && get_exec_env()->log_state)
> +	if (!WARN_ON_ONCE(!in_task()) && get_exec_env()->log_state) {
> +		update_log_time(get_exec_env());
>  		log = get_exec_env()->log_state;
> +	}
>  #endif
>  	return log;
>  }

[ ... ]

> @@ -1108,6 +1114,7 @@ void log_buf_vmcoreinfo_setup(void)
>  	VMCOREINFO_OFFSET(printk_info, text_len);
>  	VMCOREINFO_OFFSET(printk_info, caller_id);
>  	VMCOREINFO_OFFSET(printk_info, dev_info);
> +	VMCOREINFO_OFFSET(printk_info, time_offset);

[Severity: Low]
Is the size of the new field intended? struct printk_info now embeds a
32-byte struct timens_offsets (two timespec64) in every descriptor, but
only the boottime offset is used.

That grows the static host __log_buf infos array and every per-VE
ringbuffer infos array. SIZE(printk_info) also changes and a new
OFFSET(printk_info.time_offset) is exported, so dump tools such as crash
and makedumpfile would need updating.

Would a per-log value, or a 16-byte boottime delta, be enough? The commit
message does not mention the size or vmcoreinfo change.

[ ... ]

> @@ -2402,6 +2411,8 @@ static int vprintk_store_log(struct log_state *log, int facility, int level,
>  	if (dev_info)
>  		memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info));
>  
> +	r.info->time_offset = log->time_offset;
> +

[Severity: Medium]
Can this store a zero or stale time_offset for records coming from
ve_log_printk()?

ve_log_printk() calls ve_log_vprintk(), which for a non-super VE calls
vprintk_emit_log() directly:

r = vprintk_emit_log(ve->log_state, 0, LOGLEVEL_DEFAULT, NULL,
		     fmt, args);

That path never goes through ve_log_state() or __ve_log_state(), which
are the only callers of update_log_time(). vprintk_store_log() then
copies whatever is in log->time_offset.

The field is zero from the kzalloc in ve_log_init() unless some other
lookup has updated it. The record would then be stored with an unshifted
host uptime, which is the leak this patch is meant to prevent.

Should the offsets be refreshed on this path as well?

-- 
Sashiko AI review · https://sashiko.vzint.dev/#/patchset/20261002-ve-printk-irq-v1-0-cb55896d455c@virtuozzo.com?part=4