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

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

On 10/7/26 00:04, no-reply@sashiko.virtuozzo.com wrote:
> Thank you for your contribution! Sashiko AI review found 3 potential issue(s) to consider:
> - [Medium] printk: time_ns refcount get/put in any-context vprintk_store_log() path
> - [Low] printk: boottime shift baked in at store time leaves early records unshifted
> - [Low] printk: init_log_state references ve0 without a CONFIG_VE guard
> --
> 
> commit 5c30ca9d767fcbace4f34b24a8dcf1364e21ebb6
> Author: Vladimir Riabchun <vladimir.riabchun@virtuozzo.com>
> 
> ve/printk: Fix time virtualization
> 
> This patch moves the container boottime shift from print time (where
> get_exec_env() was used) to message store time in vprintk_store_log().
> The shift now uses the owning VE of the log_state, so IRQ printks no
> longer pick up the wrong container's offsets.
> 
> 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
> 
> [ ... ]
> 
>> +#define GET_VE_LOG(ve) ((struct log_state *) ve->log_state)
>> +
> 
> [Severity: Low]
> This isn't a bug, but GET_VE_LOG() is not used anywhere in kernel/printk,
> and it does not parenthesize its argument, so GET_VE_LOG(a + b) would
> expand to a + b->log_state. Is the macro needed in this patch?

True, missed it. Will remove in v3.

> 
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
> 
> [ ... ]
> 
>> @@ -534,6 +534,7 @@ struct log_state init_log_state = {
>>   		.val[1]	= 0,
>>   	},
>>   	.prb = &printk_rb_static,
>> +	.owner_ve = &ve0,
>>   };
> 
> [Severity: Low]
> Will this build when CONFIG_PRINTK=y and CONFIG_VE=n? The declaration
> extern struct ve_struct ve0; in include/linux/ve_proto.h is inside
> #ifdef CONFIG_VE, and the !CONFIG_VE branch only provides the get_ve0()
> stub.
> 
> Other VE-specific code in this file is guarded by #ifdef CONFIG_VE, so
> should the .owner_ve initializer be guarded in the same way?

Eh, will fix in v3.

> 
> [ ... ]
> 
>> -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;
> 
> [ ... ]
> 
>> @@ -2329,6 +2325,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);
> 
> [Severity: Medium]
> Can this take and drop a time_ns reference from a context where the final
> put is unsafe?
> 
> vprintk_store_log() runs in the any-context store path, after
> printk_enter_irqsave(). It now calls:
> 
> vprintk_store_log()
>    ve_timens_add_boottime_ns()
>      ve_get_time_ns()     /* get_time_ns() under rcu_read_lock() */
>      put_time_ns()
> 
> ve_get_time_ns() holds the reference past the RCU section. Consider the
> teardown side in ve_drop_context():
> 
> rcu_assign_pointer(ve->ve_nsproxy, NULL);
> synchronize_rcu();
> put_nsproxy(ve_nsproxy);
> 
> If a printk took its reference before the pointer was cleared, can it end
> up holding the last time_ns reference? In that case put_time_ns() would
> call free_time_ns() from inside the printk store path, which may be in
> hardirq or other atomic context.
> 
> Separately, this adds an RCU lock plus an atomic inc/dec on every printk
> record, including host (ve0) records, where it touches init_time_ns.
> 
> Would it be possible to read the offsets under RCU without taking a
> reference, cache the boottime offset in log_state, or skip ve0?

According to RCU doc: "anything that disables bottom halves, preemption,
or interrupts also enters an RCU read-side critical section."

ve_timens_add_boottime_ns is called from vprintk_store_log right after
printk_enter_irqsave, so synchronize_rcu will wait anyway.

Also: ve_exit_ns means that VE is stopped and no tasks are there.
But reaching printk with given VE means that either an interrupted task
is still in VE or we got it from somewhere like net structure.
In any case, this is not a deferred usage, so we can't use stale values
there.

About performance - I don't think it's a big problem. Dmesg logs are
expected to be rare enough, frequent printing is bounded by serial
console and may cause stalls.

> 
> [Severity: Low]
> Is it intended that records stored while ve->ve_nsproxy is NULL keep the
> raw host uptime permanently?
> 
> ve_log_init() runs at css_alloc, but ve_nsproxy is only set later by
> ve_grab_context(). Until then ve_get_time_ns() returns NULL and
> ve_timens_add_boottime_ns() returns the value unshifted:
> 
> 	if (unlikely(!ve_time_ns)) {
> 		/* container not yet started */
> 		return nsec;
> 	}
> 
> Before this patch the shift was applied at read time, so every record
> was shifted consistently once the container had started. Now the
> container's dmesg can show a mixed timeline, and the raw ts_nsec in the
> VE ring buffer differs from what was read before. The commit message does
> not mention this change in behavior.

Shifting time when printing was not reliable as well, it could happen
anytime.

The idea of this whole patchset is to avoid printing messages to
random containers. We normally can't get a situation when VE is stopped
and there are processes inside it(except selftests), so it is not
possible to print into stopped VE.

> 
> [ ... ]
> 

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

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