2015-06-02 10:31:56

by Jiri Bohac

[permalink] [raw]
Subject: Re: [RFC][PATCH 3/4] ntp: Use printk_deferred in leapsecond path

Hi,

On Fri, May 29, 2015 at 01:24:27PM -0700, John Stultz wrote:
> Looking over the leapsecond code, I noticed the printk messages
> reporting the leapsecond insertion in the second_overflow path
> were not using the printk_deferred method. This was surprising
> since the printk_deferred method was added in part to avoid
> printk-ing while holding the timekeeping locks.
>
> See 6d9bcb621b0b (timekeeping: use printk_deferred when holding
> timekeeping seqlock) for further rational.
>
> I can only guess that this omission was a git add -p oversight.

second_overflow() is called from accumulate_nsecs_to_secs().

accumulate_nsecs_to_secs() is called from update_wall_time()
- once directly
- once via logarithmic_accumulation()
Both calls are before write_seqcount_begin(&tk_core.seq).

So it looks safe to use printk there.

Regards,

--
Jiri Bohac <[email protected]>
SUSE Labs, SUSE CZ


2015-06-02 10:43:43

by Jiri Kosina

[permalink] [raw]
Subject: Re: [RFC][PATCH 3/4] ntp: Use printk_deferred in leapsecond path

On Tue, 2 Jun 2015, Jiri Bohac wrote:

> > Looking over the leapsecond code, I noticed the printk messages
> > reporting the leapsecond insertion in the second_overflow path
> > were not using the printk_deferred method. This was surprising
> > since the printk_deferred method was added in part to avoid
> > printk-ing while holding the timekeeping locks.
> >
> > See 6d9bcb621b0b (timekeeping: use printk_deferred when holding
> > timekeeping seqlock) for further rational.
> >
> > I can only guess that this omission was a git add -p oversight.
>
> second_overflow() is called from accumulate_nsecs_to_secs().
>
> accumulate_nsecs_to_secs() is called from update_wall_time()
> - once directly
> - once via logarithmic_accumulation()
> Both calls are before write_seqcount_begin(&tk_core.seq).
>
> So it looks safe to use printk there.

Couldn't we stuff a couple of

!lockdep_is_held()

assertions into printk() so that we don't have to keep rediscovering this
sort of problems over and over again?

Thanks,

--
Jiri Kosina
SUSE Labs

2015-06-02 16:04:45

by John Stultz

[permalink] [raw]
Subject: Re: [RFC][PATCH 3/4] ntp: Use printk_deferred in leapsecond path

On Tue, Jun 2, 2015 at 3:31 AM, Jiri Bohac <[email protected]> wrote:
> Hi,
>
> On Fri, May 29, 2015 at 01:24:27PM -0700, John Stultz wrote:
>> Looking over the leapsecond code, I noticed the printk messages
>> reporting the leapsecond insertion in the second_overflow path
>> were not using the printk_deferred method. This was surprising
>> since the printk_deferred method was added in part to avoid
>> printk-ing while holding the timekeeping locks.
>>
>> See 6d9bcb621b0b (timekeeping: use printk_deferred when holding
>> timekeeping seqlock) for further rational.
>>
>> I can only guess that this omission was a git add -p oversight.
>
> second_overflow() is called from accumulate_nsecs_to_secs().
>
> accumulate_nsecs_to_secs() is called from update_wall_time()
> - once directly
> - once via logarithmic_accumulation()
> Both calls are before write_seqcount_begin(&tk_core.seq).
>
> So it looks safe to use printk there.

Good point. The update is being done to the shadow-timekeeper, so we
won't block readers. This can probably be dropped then. Although I'm
almost consider keeping it for consistency so I don't forget this
again and worry about it in the future.

thanks
-john

2015-06-02 16:14:24

by John Stultz

[permalink] [raw]
Subject: Re: [RFC][PATCH 3/4] ntp: Use printk_deferred in leapsecond path

On Tue, Jun 2, 2015 at 3:43 AM, Jiri Kosina <[email protected]> wrote:
> On Tue, 2 Jun 2015, Jiri Bohac wrote:
>
>> > Looking over the leapsecond code, I noticed the printk messages
>> > reporting the leapsecond insertion in the second_overflow path
>> > were not using the printk_deferred method. This was surprising
>> > since the printk_deferred method was added in part to avoid
>> > printk-ing while holding the timekeeping locks.
>> >
>> > See 6d9bcb621b0b (timekeeping: use printk_deferred when holding
>> > timekeeping seqlock) for further rational.
>> >
>> > I can only guess that this omission was a git add -p oversight.
>>
>> second_overflow() is called from accumulate_nsecs_to_secs().
>>
>> accumulate_nsecs_to_secs() is called from update_wall_time()
>> - once directly
>> - once via logarithmic_accumulation()
>> Both calls are before write_seqcount_begin(&tk_core.seq).
>>
>> So it looks safe to use printk there.
>
> Couldn't we stuff a couple of
>
> !lockdep_is_held()
>
> assertions into printk() so that we don't have to keep rediscovering this
> sort of problems over and over again?

Yea. I was thinking if we could add something very early in printk
before we disable lockdep where we lockdep_aquire/release a few of the
locks we know printk might take, it would help close the gap on these
sorts of call paths that surprise us.

Lockdep is *such* a great tool, because it provides some confidence
that changes don't cause locking regressions, so to have printk poke a
hole in that confidence is frustrating.

thanks
-john