lkml.org 
[lkml]   [2020]   [Nov]   [27]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Date
SubjectRe: [PATCH v3] lockdep: Allow tuning tracing capacity constants.
On Sun, Nov 22, 2020 at 2:56 AM Tetsuo Handa
<penguin-kernel@i-love.sakura.ne.jp> wrote:
>
> On 2020/11/20 18:27, Dmitry Vyukov wrote:
> > Peter, so far it looks like just a very large, but normal graph to me.
> > The cheapest from an engineering point of view solution would be just
> > to increase the constants. I assume a 2x increase should buy us lots
> > of time to overflow.
> > I can think of more elaborate solutions, e.g. using bitmasks to
> > represent hot leaf and top-level locks. But it will both increase the
> > resulting code complexity (no uniform representation anymore, all code
> > will need to deal with different representations) and require some
> > time investments (that I can't justify for me at least as compared to
> > just throwing a bit more machine memory at it). And in the end it
> > won't really reduce the size of the graph.
> > What do you think?
> >
>
> Yes, I think it is a normal graph; simply syzkaller kernels tend to record
> a few times more dependencies than my idle kernel (shown bottom).
>
> Peter, you guessed that the culprit is sysfs at
> https://lkml.kernel.org/r/20200916115057.GO2674@hirez.programming.kicks-ass.net , but
> syzbot reported at https://syzkaller.appspot.com/text?tag=MachineInfo&x=99b8f2b092d9714f
> that "BUG: MAX_LOCKDEP_ENTRIES too low!" can occur on a VM with only 2 CPUs.
> Is your guess catching the culprit?
>
> We could improve a few locks, but as a whole we won't be able to afford keeping
> sum of individual dependencies under current threshold. Therefore, allow lockdep to
> tune the capacity and allow syzkaller to dump when reaching the capacity will be
> the way to go.
>
>
>
> # cat /proc/lockdep_stats
> lock-classes: 1236 [max: 8192]
> direct dependencies: 9610 [max: 32768]
> indirect dependencies: 40401
> all direct dependencies: 174635
> dependency chains: 11398 [max: 65536]
> dependency chain hlocks used: 42830 [max: 327680]
> dependency chain hlocks lost: 0
> in-hardirq chains: 61
> in-softirq chains: 414
> in-process chains: 10923
> stack-trace entries: 93041 [max: 524288]
> number of stack traces: 4997
> number of stack hash chains: 4292
> combined max dependencies: 281074520
> hardirq-safe locks: 50
> hardirq-unsafe locks: 805
> softirq-safe locks: 146
> softirq-unsafe locks: 722
> irq-safe locks: 155
> irq-unsafe locks: 805
> hardirq-read-safe locks: 2
> hardirq-read-unsafe locks: 129
> softirq-read-safe locks: 11
> softirq-read-unsafe locks: 123
> irq-read-safe locks: 11
> irq-read-unsafe locks: 129
> uncategorized locks: 224
> unused locks: 0
> max locking depth: 15
> max bfs queue depth: 215
> chain lookup misses: 11664
> chain lookup hits: 37393935
> cyclic checks: 11053
> redundant checks: 0
> redundant links: 0
> find-mask forwards checks: 1588
> find-mask backwards checks: 1779
> hardirq on events: 17502380
> hardirq off events: 17502376
> redundant hardirq ons: 0
> redundant hardirq offs: 0
> softirq on events: 90845
> softirq off events: 90845
> redundant softirq ons: 0
> redundant softirq offs: 0
> debug_locks: 1
>
> zapped classes: 0
> zapped lock chains: 0
> large chain blocks: 1
> # awk ' { if ($2 == "OPS:") print $5" "$9 } ' /proc/lockdep | sort -rV | head -n 30
> 423 (wq_completion)events
> 405 (wq_completion)events_unbound
> 393 &f->f_pos_lock
> 355 &p->lock
> 349 sb_writers#3
> 342 sb_writers#6
> 338 &of->mutex
> 330 (work_completion)(&entry->work)
> 330 pernet_ops_rwsem
> 289 epmutex
> 288 &ep->mtx
> 281 tty_mutex
> 280 &tty->legacy_mutex
> 273 &tty->legacy_mutex/1
> 269 &tty->ldisc_sem
> 268 (wq_completion)ipv6_addrconf
> 266 (work_completion)(&(&ifa->dad_work)->work)
> 266 (linkwatch_work).work
> 266 (addr_chk_work).work
> 266 &ldata->atomic_read_lock
> 265 (work_completion)(&buf->work)
> 265 rtnl_mutex
> 263 &tty->atomic_write_lock
> 262 &buf->lock
> 261 &tty->termios_rwsem
> 242 &port->buf.lock/1
> 242 kn->active#40
> 241 &o_tty->termios_rwsem/1
> 240 registration_lock
> 239 &ldata->output_lock
> # awk ' { if ($2 == "OPS:") print $7" "$9 } ' /proc/lockdep | sort -rV | head -n 30
> 642 pool_lock
> 641 &obj_hash[i].lock
> 582 tk_core.seq.seqcount
> 561 hrtimer_bases.lock
> 560 &rt_rq->rt_runtime_lock
> 559 &rt_b->rt_runtime_lock
> 559 &cp->lock
> 559 &cfs_rq->removed.lock
> 559 &cfs_b->lock
> 558 &rq->lock
> 550 &tsk->delays->lock
> 549 &p->pi_lock
> 506 &base->lock
> 504 &n->list_lock
> 432 &____s->seqcount
> 404 &x->wait#10
> 401 &pool->lock
> 369 &zone->lock
> 330 rcu_node_0
> 326 &(kretprobe_table_locks[i].lock)
> 326 pgd_lock
> 324 &pgdat->lru_lock
> 323 lock#5
> 321 &page_wait_table[i]
> 319 ptlock_ptr(page)#2/1
> 318 ptlock_ptr(page)#2
> 316 &sem->wait_lock
> 316 &mm->page_table_lock
> 316 ptlock_ptr(page)
> 315 &anon_vma->rwsem

The latest syzbot logs now contain these dumps as well, if anybody is
interested in more:
https://syzkaller.appspot.com/bug?id=63fc8d0501c39609dd2f268e4190ec9a72619563
https://syzkaller.appspot.com/bug?id=3d97ba93fb3566000c1c59691ea427370d33ea1b

\
 
 \ /
  Last update: 2020-11-27 10:02    [W:2.027 / U:0.060 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site