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

[no-reply@sashiko.virtuozzo.com]

Thank you for your contribution! Sashiko AI review found 3 potential issue(s) to consider:
- [Medium] printk: vprintk_store_log() can drop last time_ns ref and run free_time_ns()
- [Medium] ve/printk: store-time boottime shift leaves pre-start/post-stop VE records on host time
- [Low] printk: refcounted time_ns get/put on every message in vprintk_store_log()
--

commit d24cdca46b24c622f9dc8616a9a118ce2d8625f8
Author: Vladimir Riabchun <vladimir.riabchun@virtuozzo.com>

ve/printk: Fix time virtualization

This patch moves the container boottime offset adjustment from the
read side (print_time() and info_print_ext_header()) to the store side
in vprintk_store_log(). The offset is taken from the time namespace of
the VE that owns the destination log_state, via a new owner_ve field.

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

> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c

[ ... ]

> -static inline u64 ve_timens_add_boottime_ns(u64 nsec)
> +static inline u64 ve_timens_add_boottime_ns(u64 nsec, struct ve_struct *ve)
>  {
>  	struct time_namespace *ve_time_ns;
>  	struct timens_offsets *ns_offsets;
>  
> -	ve_time_ns = ve_get_time_ns(get_exec_env());
> +	ve_time_ns = ve_get_time_ns(ve);
>  	if (unlikely(!ve_time_ns)) {
>  		/* container not yet started */
>  		return nsec;
>  	}

[Severity: Low]
Is a counted reference needed here? ve_get_time_ns() does a
refcount_inc() on the time_ns under rcu_read_lock(), and the function
only reads the offsets before calling put_time_ns().

ve0 is not special-cased. init_ve has ve_nsproxy pointing at
init_nsproxy, so every host printk now reaches vprintk_store_log() ->
ve_timens_add_boottime_ns() -> ve_get_time_ns() -> get_time_ns() and
increments the init_time_ns refcount, with IRQs disabled inside
printk_enter_irqsave(). Previously this cost was paid only on the
reader side, in process context.

Could the offsets be read under rcu_read_lock() without taking a
reference?

[Severity: Medium]
Can the put_time_ns() here be the last put and run free_time_ns() from
the printk store path?

The sequence in ve_drop_context() is:

    rcu_assign_pointer(ve->ve_nsproxy, NULL);
    synchronize_rcu();
    put_nsproxy(ve_nsproxy);

A printer that took its time_ns reference through ve_get_time_ns()
before the pointer was cleared keeps its own reference. If it runs
concurrently with container stop, and the container tasks are already
gone, its put_time_ns() in ve_timens_add_boottime_ns() can drop the
last reference.

free_time_ns() then runs inside vprintk_store_log():

    dec_time_namespaces(ns->ucounts);
    put_user_ns(ns->user_ns);
    ns_free_inum(&ns->ns);
    __free_page(ns->vvar_page);
    kfree(ns);

This takes the proc_inum_ida lock and allocator and slab locks, and may
release a user_ns. Those locks could already be held by the context
that printk interrupted, so can this recurse or deadlock, or trigger a
lockdep wait-context warning?

Before the patch, the get/put ran only in task context on the reader
side. After it, any log with owner_ve set does the get/put on the store
path. The failcount patch later in this series adds
__ve_pr_warn_ratelimited() calls from ve_failcount_inc() with an
explicit ve, and those can come from arbitrary and atomic contexts.

Could the offsets be read without a counted reference, or the put be
deferred?

[ ... ]

> @@ -1431,9 +1432,6 @@ static size_t print_time(u64 ts, char *buf)
>  {
>  	unsigned long rem_nsec;
>  
> -	/* shift the timestamp on the Container uptime value */
> -	ts = ve_timens_add_boottime_ns(ts);
> -
>  	rem_nsec = do_div(ts, 1000000000);

[Severity: Medium]
Is it intended that records stored while the VE has no ve_nsproxy now
keep the raw host timestamp permanently?

With the read-side shift removed here, print_time() and
info_print_ext_header() print whatever is in the ring buffer. In
vprintk_store_log(), ve_timens_add_boottime_ns() returns the unshifted
local_clock() value when ve_get_time_ns() returns NULL ("container not
yet started").

ve_nsproxy is NULL before ve_grab_context() in ve_start_container(),
while ve_log_init() sets up the log_state at cgroup creation. It is NULL
again after ve_drop_context(), which runs in the start error path and
when the VE is stopped.

The VE log can be written in those windows, since __ve_vprintk_emit()
and ve_log_printk() only check ve_is_super() and not whether the VE is
running. For example, ve_log_printk(net->owner_ve, ...) from
net/netfilter/nf_log.c, or ve_printk(VE_LOG, ...) from kernel/exit.c,
mm/memory.c, net/core/dev.c and net/ipv4/netfilter/ip_tables.c.

Records stored before start or after stop would then carry host uptime,
while records stored in between carry host uptime plus the (usually
negative) container boottime offset. Can the same container dmesg or
/dev/kmsg then show large timestamps followed by small ones?

Since nothing re-bases old records at read time any more, would it make
sense to mention this trade-off in the commit message?

[ ... ]

> @@ -2329,6 +2327,7 @@ static int vprintk_store_log(struct log_state *log, int facility, int level,
>  	 * timestamp with respect to the caller.
>  	 */
>  	ts_nsec = local_clock();
> +	ts_nsec = ve_timens_add_boottime_ns(ts_nsec, log->owner_ve);

This is the call site for the two comments above on
ve_timens_add_boottime_ns().

>  
>  	caller_id = printk_caller_id();

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

_______________________________________________
Devel mailing list
Devel@openvz.org
https://lists.openvz.org/mailman/listinfo/devel