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

[Vladimir Riabchun <vladimir.riabchun@virtuozzo.com>]

On 10/12/26 01:03, no-reply@sashiko.virtuozzo.com wrote:
> 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?

Wouldn't bother. Printing to dmesg should be relatively rare event.
This is not the biggest overhead there. Also, previously the cost was
paid when printing to log, possibly in IRQ. Now the one who prints
does this.

> 
> [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?

Replied in 
http://lore.virtuozzo.com/kernel/c70733bf-a171-4927-98f5-120deb7ed173@virtuozzo.com/.

> 
> [ ... ]
> 
>> @@ -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.

Replied in 
http://lore.virtuozzo.com/kernel/c70733bf-a171-4927-98f5-120deb7ed173@virtuozzo.com/

> 
> 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();
> 

-- 
Best regards, Riabchun Vladimir
Linux Kernel Developer, Virtuozzo

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