spinlock_debug.c 15 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589
  1. /*
  2. * Copyright 2005, Red Hat, Inc., Ingo Molnar
  3. * Released under the General Public License (GPL).
  4. *
  5. * This file contains the spinlock/rwlock implementations for
  6. * DEBUG_SPINLOCK.
  7. */
  8. #include <linux/spinlock.h>
  9. #include <linux/nmi.h>
  10. #include <linux/interrupt.h>
  11. #include <linux/debug_locks.h>
  12. #include <linux/delay.h>
  13. #include <linux/export.h>
  14. #include <kernel/sched/sched.h>
  15. #ifdef CONFIG_MTK_AEE_FEATURE
  16. #include <mt-plat/aee.h>
  17. #endif
  18. #if defined(MTK_DEBUG_SPINLOCK_V1) || defined(MTK_DEBUG_SPINLOCK_V2)
  19. #include <linux/sched/clock.h>
  20. #include <linux/sched/debug.h>
  21. #define MAX_LOCK_NAME 128
  22. #define WARNING_TIME 1000000000 /* 1 seconds */
  23. static long long msec_high(unsigned long long nsec)
  24. {
  25. if ((long long)nsec < 0) {
  26. nsec = -nsec;
  27. do_div(nsec, 1000000);
  28. return -nsec;
  29. }
  30. do_div(nsec, 1000000);
  31. return nsec;
  32. }
  33. static long long sec_high(unsigned long long nsec)
  34. {
  35. if ((long long)nsec < 0) {
  36. nsec = -nsec;
  37. do_div(nsec, 1000000000);
  38. return -nsec;
  39. }
  40. do_div(nsec, 1000000000);
  41. return nsec;
  42. }
  43. static unsigned long sec_low(unsigned long long nsec)
  44. {
  45. if ((long long)nsec < 0)
  46. nsec = -nsec;
  47. /* exclude part of nsec */
  48. return do_div(nsec, 1000000000)/1000;
  49. }
  50. static void get_spin_lock_name(raw_spinlock_t *lock, char *name)
  51. {
  52. #ifdef CONFIG_DEBUG_LOCK_ALLOC
  53. snprintf(name, MAX_LOCK_NAME, "%s", lock->dep_map.name);
  54. #else
  55. snprintf(name, MAX_LOCK_NAME, "%ps", lock);
  56. #endif
  57. }
  58. #endif /* MTK_DEBUG_SPINLOCK_V1 || MTK_DEBUG_SPINLOCK_V2 */
  59. static bool is_critical_spinlock(raw_spinlock_t *lock)
  60. {
  61. #ifdef CONFIG_DEBUG_LOCK_ALLOC
  62. /* The lock is needed by kmalloc and aee_kernel_warning_api */
  63. if (!strcmp(lock->dep_map.name, "&(&n->list_lock)->rlock"))
  64. return true;
  65. if (!strcmp(lock->dep_map.name, "depot_lock"))
  66. return true;
  67. /* The following locks are in the white list */
  68. if (!strcmp(lock->dep_map.name, "show_lock"))
  69. return true;
  70. #endif
  71. return false;
  72. }
  73. static bool is_critical_lock_held(void)
  74. {
  75. int cpu;
  76. struct rq *rq;
  77. cpu = raw_smp_processor_id();
  78. rq = cpu_rq(cpu);
  79. /* The lock is needed by aee_kernel_warning_api */
  80. if (raw_spin_is_locked(&rq->lock))
  81. return true;
  82. return false;
  83. }
  84. #ifdef MTK_DEBUG_SPINLOCK_V2
  85. static void spin_lock_get_timestamp(unsigned long long *ts)
  86. {
  87. *ts = sched_clock();
  88. }
  89. static void spin_lock_check_spinning_time(raw_spinlock_t *lock,
  90. unsigned long long ts)
  91. {
  92. unsigned long long te;
  93. te = sched_clock();
  94. if (te - ts > WARNING_TIME) {
  95. char lock_name[MAX_LOCK_NAME];
  96. get_spin_lock_name(lock, lock_name);
  97. pr_info("spinning for (%s)(%p) from [%lld.%06lu] to [%lld.%06lu], total %llu ms\n",
  98. lock_name, lock,
  99. sec_high(ts), sec_low(ts),
  100. sec_high(te), sec_low(te),
  101. msec_high(te - ts));
  102. }
  103. }
  104. static void spin_lock_check_holding_time(raw_spinlock_t *lock)
  105. {
  106. /* check if holding time over 1 second */
  107. if (lock->unlock_t - lock->lock_t > WARNING_TIME) {
  108. char lock_name[MAX_LOCK_NAME];
  109. char aee_str[128];
  110. get_spin_lock_name(lock, lock_name);
  111. pr_info("hold spinlock (%s)(%p) from [%lld.%06lu] to [%lld.%06lu], total %llu ms\n",
  112. lock_name, lock,
  113. sec_high(lock->lock_t), sec_low(lock->lock_t),
  114. sec_high(lock->unlock_t), sec_low(lock->unlock_t),
  115. msec_high(lock->unlock_t - lock->lock_t));
  116. if (is_critical_spinlock(lock) || is_critical_lock_held())
  117. return;
  118. pr_info("========== The call trace of lock owner on CPU%d ==========\n",
  119. raw_smp_processor_id());
  120. dump_stack();
  121. #if defined(CONFIG_MTK_AEE_FEATURE) && \
  122. !defined(CONFIG_KASAN) && !defined(CONFIG_UBSAN)
  123. snprintf(aee_str, sizeof(aee_str),
  124. "Spinlock lockup: (%s) in %s\n",
  125. lock_name, current->comm);
  126. aee_kernel_warning_api(__FILE__, __LINE__,
  127. DB_OPT_DUMMY_DUMP | DB_OPT_FTRACE,
  128. aee_str, "spinlock debugger\n");
  129. #endif
  130. }
  131. }
  132. #else /* MTK_DEBUG_SPINLOCK_V2 */
  133. static inline void spin_lock_get_timestamp(unsigned long long *ts)
  134. {
  135. }
  136. static inline void
  137. spin_lock_check_spinning_time(raw_spinlock_t *lock, unsigned long long ts)
  138. {
  139. }
  140. static inline void spin_lock_check_holding_time(raw_spinlock_t *lock)
  141. {
  142. }
  143. #endif /* !MTK_DEBUG_SPINLOCK_V2 */
  144. void __raw_spin_lock_init(raw_spinlock_t *lock, const char *name,
  145. struct lock_class_key *key, short inner)
  146. {
  147. #ifdef CONFIG_DEBUG_LOCK_ALLOC
  148. /*
  149. * Make sure we are not reinitializing a held lock:
  150. */
  151. debug_check_no_locks_freed((void *)lock, sizeof(*lock));
  152. lockdep_init_map_wait(&lock->dep_map, name, key, 0, inner);
  153. #endif
  154. lock->raw_lock = (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED;
  155. lock->magic = SPINLOCK_MAGIC;
  156. lock->owner = SPINLOCK_OWNER_INIT;
  157. lock->owner_cpu = -1;
  158. }
  159. EXPORT_SYMBOL(__raw_spin_lock_init);
  160. void __rwlock_init(rwlock_t *lock, const char *name,
  161. struct lock_class_key *key)
  162. {
  163. #ifdef CONFIG_DEBUG_LOCK_ALLOC
  164. /*
  165. * Make sure we are not reinitializing a held lock:
  166. */
  167. debug_check_no_locks_freed((void *)lock, sizeof(*lock));
  168. lockdep_init_map_wait(&lock->dep_map, name, key, 0, LD_WAIT_CONFIG);
  169. #endif
  170. lock->raw_lock = (arch_rwlock_t) __ARCH_RW_LOCK_UNLOCKED;
  171. lock->magic = RWLOCK_MAGIC;
  172. lock->owner = SPINLOCK_OWNER_INIT;
  173. lock->owner_cpu = -1;
  174. }
  175. EXPORT_SYMBOL(__rwlock_init);
  176. static void spin_dump(raw_spinlock_t *lock, const char *msg)
  177. {
  178. struct task_struct *owner = READ_ONCE(lock->owner);
  179. if (owner == SPINLOCK_OWNER_INIT)
  180. owner = NULL;
  181. printk(KERN_EMERG "BUG: spinlock %s on CPU#%d, %s/%d\n",
  182. msg, raw_smp_processor_id(),
  183. current->comm, task_pid_nr(current));
  184. printk(KERN_EMERG " lock: %pS, .magic: %08x, .owner: %s/%d, "
  185. ".owner_cpu: %d\n",
  186. lock, READ_ONCE(lock->magic),
  187. owner ? owner->comm : "<none>",
  188. owner ? task_pid_nr(owner) : -1,
  189. READ_ONCE(lock->owner_cpu));
  190. dump_stack();
  191. }
  192. static void spin_bug(raw_spinlock_t *lock, const char *msg)
  193. {
  194. char aee_str[50];
  195. if (!debug_locks_off())
  196. return;
  197. spin_dump(lock, msg);
  198. snprintf(aee_str, sizeof(aee_str), "%s: [%s]\n", current->comm, msg);
  199. if (!strcmp(msg, "bad magic") || !strcmp(msg, "already unlocked")
  200. || !strcmp(msg, "wrong owner") || !strcmp(msg, "wrong CPU")
  201. || !strcmp(msg, "uninitialized")) {
  202. pr_info("%s", aee_str);
  203. pr_info("maybe use an un-initial spin_lock or mem corrupt\n");
  204. pr_info("maybe already unlocked or wrong owner or wrong CPU\n");
  205. pr_info("maybe bad magic %08x, should be %08x\n",
  206. lock->magic, SPINLOCK_MAGIC);
  207. pr_info(">>>>>>>>>>>>>> Let's KE <<<<<<<<<<<<<<\n");
  208. BUG_ON(1);
  209. }
  210. if (!is_critical_spinlock(lock) && !is_critical_lock_held()) {
  211. #ifdef CONFIG_MTK_AEE_FEATURE
  212. aee_kernel_warning_api(__FILE__, __LINE__,
  213. DB_OPT_DUMMY_DUMP | DB_OPT_FTRACE,
  214. aee_str, "spinlock debugger\n");
  215. #endif
  216. }
  217. }
  218. #define SPIN_BUG_ON(cond, lock, msg) if (unlikely(cond)) spin_bug(lock, msg)
  219. static inline void
  220. debug_spin_lock_before(raw_spinlock_t *lock)
  221. {
  222. #ifdef CONFIG_DEBUG_LOCK_ALLOC
  223. SPIN_BUG_ON(lock->dep_map.name == NULL, lock, "uninitialized");
  224. #endif
  225. SPIN_BUG_ON(READ_ONCE(lock->magic) != SPINLOCK_MAGIC, lock, "bad magic");
  226. SPIN_BUG_ON(READ_ONCE(lock->owner) == current, lock, "recursion");
  227. SPIN_BUG_ON(READ_ONCE(lock->owner_cpu) == raw_smp_processor_id(),
  228. lock, "cpu recursion");
  229. }
  230. static inline void debug_spin_lock_after(raw_spinlock_t *lock)
  231. {
  232. lock->lock_t = sched_clock();
  233. WRITE_ONCE(lock->owner_cpu, raw_smp_processor_id());
  234. WRITE_ONCE(lock->owner, current);
  235. }
  236. static inline void debug_spin_unlock(raw_spinlock_t *lock)
  237. {
  238. SPIN_BUG_ON(lock->magic != SPINLOCK_MAGIC, lock, "bad magic");
  239. SPIN_BUG_ON(!raw_spin_is_locked(lock), lock, "already unlocked");
  240. SPIN_BUG_ON(lock->owner != current, lock, "wrong owner");
  241. SPIN_BUG_ON(lock->owner_cpu != raw_smp_processor_id(),
  242. lock, "wrong CPU");
  243. WRITE_ONCE(lock->owner, SPINLOCK_OWNER_INIT);
  244. WRITE_ONCE(lock->owner_cpu, -1);
  245. lock->unlock_t = sched_clock();
  246. spin_lock_check_holding_time(lock);
  247. }
  248. #ifdef MTK_DEBUG_SPINLOCK_V1
  249. #define LOCK_CSD_IN_USE ((void *)-1L)
  250. static DEFINE_PER_CPU(call_single_data_t, spinlock_debug_csd);
  251. struct spinlock_debug_info {
  252. int detector_cpu;
  253. raw_spinlock_t lock;
  254. };
  255. static DEFINE_PER_CPU(struct spinlock_debug_info, sp_dbg) = {
  256. -1, __RAW_SPIN_LOCK_UNLOCKED(sp_dbg.lock) };
  257. static void show_cpu_backtrace(void *info)
  258. {
  259. call_single_data_t *csd;
  260. pr_info("========== The call trace of lock owner on CPU%d ==========\n",
  261. raw_smp_processor_id());
  262. dump_stack();
  263. if (info != LOCK_CSD_IN_USE) {
  264. #if defined(CONFIG_MTK_AEE_FEATURE) && \
  265. !defined(CONFIG_KASAN) && !defined(CONFIG_UBSAN)
  266. char aee_str[128];
  267. snprintf(aee_str, sizeof(aee_str),
  268. "Spinlock lockup: (%s) in %s\n",
  269. (char *)info, current->comm);
  270. aee_kernel_warning_api(__FILE__, __LINE__,
  271. DB_OPT_DUMMY_DUMP | DB_OPT_FTRACE,
  272. aee_str, "spinlock debugger\n");
  273. #endif
  274. kfree(info);
  275. }
  276. csd = this_cpu_ptr(&spinlock_debug_csd);
  277. csd->info = NULL;
  278. }
  279. bool is_logbuf_lock_held(raw_spinlock_t *lock)
  280. {
  281. #ifdef CONFIG_DEBUG_LOCK_ALLOC
  282. /* The lock is needed by kmalloc and aee_kernel_warning_api */
  283. if (!strcmp(lock->dep_map.name, "logbuf_lock"))
  284. return true;
  285. #endif
  286. return false;
  287. }
  288. static void __spin_lock_debug(raw_spinlock_t *lock)
  289. {
  290. u64 one_second = (u64)loops_per_jiffy * msecs_to_jiffies(1000);
  291. u64 loops = one_second;
  292. int owner_cpu = -1, target_cpu = -1;
  293. int curr_cpu = raw_smp_processor_id();
  294. int print_once = 1, cnt = 0;
  295. int is_warning_owner = 0;
  296. char lock_name[MAX_LOCK_NAME];
  297. unsigned long long t1, t2, t3;
  298. struct task_struct *owner = NULL;
  299. cycles_t start;
  300. /* skip debugging */
  301. if (is_logbuf_lock_held(lock)) {
  302. arch_spin_lock(&lock->raw_lock);
  303. return;
  304. }
  305. t1 = sched_clock();
  306. t2 = t1;
  307. start = get_cycles();
  308. for (;;) {
  309. while ((get_cycles() - start) < loops) {
  310. if (arch_spin_trylock(&lock->raw_lock)) {
  311. if (is_warning_owner) {
  312. struct spinlock_debug_info *sdi;
  313. sdi = per_cpu_ptr(&sp_dbg, target_cpu);
  314. sdi->detector_cpu = -1;
  315. }
  316. return;
  317. }
  318. }
  319. loops += one_second;
  320. t3 = sched_clock();
  321. if (t3 < t2)
  322. continue;
  323. if (t3 - t2 < WARNING_TIME)
  324. continue;
  325. t2 = sched_clock();
  326. owner = lock->owner;
  327. owner_cpu = lock->owner_cpu;
  328. /* lock is already released */
  329. if (owner == SPINLOCK_OWNER_INIT || owner_cpu == -1)
  330. continue;
  331. get_spin_lock_name(lock, lock_name);
  332. pr_info("(%s)(%p) spin time: %llu ms(from %lld.%06lu), raw_lock: 0x%08x, magic: %08x, held by %s/%d on CPU#%d(from %lld.%06lu)\n",
  333. lock_name, lock,
  334. msec_high(t2 - t1), sec_high(t1), sec_low(t1),
  335. *((unsigned int *)&lock->raw_lock), lock->magic,
  336. owner->comm, task_pid_nr(owner), owner_cpu,
  337. sec_high(lock->lock_t), sec_low(lock->lock_t));
  338. /* print held lock information per 5 sec */
  339. if (cnt == 0) {
  340. struct spinlock_debug_info *sdi;
  341. sdi = per_cpu_ptr(&sp_dbg, owner_cpu);
  342. if (sdi->detector_cpu == -1 &&
  343. raw_spin_trylock(&sdi->lock)) {
  344. is_warning_owner = 1;
  345. sdi->detector_cpu = curr_cpu;
  346. target_cpu = owner_cpu;
  347. raw_spin_unlock(&sdi->lock);
  348. }
  349. if (sdi->detector_cpu == curr_cpu)
  350. debug_show_held_locks(owner);
  351. }
  352. cnt = (++cnt == 5) ? 0 : cnt;
  353. if (oops_in_progress != 0)
  354. /* in exception follow, printk maybe spinlock error */
  355. continue;
  356. if (!print_once || !is_warning_owner)
  357. continue;
  358. print_once = 0;
  359. if (owner_cpu != curr_cpu) {
  360. call_single_data_t *csd;
  361. csd = per_cpu_ptr(&spinlock_debug_csd, owner_cpu);
  362. /* already warned by another cpu */
  363. if (csd->info)
  364. continue;
  365. /* mark csd is in use */
  366. csd->info = LOCK_CSD_IN_USE;
  367. csd->func = show_cpu_backtrace;
  368. csd->flags = 0;
  369. if (!is_critical_spinlock(lock)
  370. && !is_critical_lock_held()) {
  371. csd->info = kmalloc(MAX_LOCK_NAME, GFP_ATOMIC);
  372. if (csd->info == NULL) {
  373. print_once = 1;
  374. continue;
  375. }
  376. strncpy(csd->info, lock_name, MAX_LOCK_NAME);
  377. }
  378. smp_call_function_single_async(owner_cpu, csd);
  379. } else {
  380. pr_info("(%s) recursive deadlock on CPU%d\n",
  381. lock_name, owner_cpu);
  382. }
  383. }
  384. }
  385. #endif /* MTK_DEBUG_SPINLOCK_V1 */
  386. /*
  387. * We are now relying on the NMI watchdog to detect lockup instead of doing
  388. * the detection here with an unfair lock which can cause problem of its own.
  389. */
  390. void do_raw_spin_lock(raw_spinlock_t *lock)
  391. {
  392. #ifdef MTK_DEBUG_SPINLOCK_V2
  393. unsigned long long ts = 0;
  394. #endif
  395. debug_spin_lock_before(lock);
  396. #if defined(MTK_DEBUG_SPINLOCK_V1)
  397. if (unlikely(!arch_spin_trylock(&lock->raw_lock)))
  398. __spin_lock_debug(lock);
  399. #elif defined(MTK_DEBUG_SPINLOCK_V2)
  400. spin_lock_get_timestamp(&ts);
  401. arch_spin_lock(&lock->raw_lock);
  402. spin_lock_check_spinning_time(lock, ts);
  403. #else
  404. arch_spin_lock(&lock->raw_lock);
  405. #endif
  406. debug_spin_lock_after(lock);
  407. }
  408. int do_raw_spin_trylock(raw_spinlock_t *lock)
  409. {
  410. int ret = arch_spin_trylock(&lock->raw_lock);
  411. if (ret)
  412. debug_spin_lock_after(lock);
  413. #ifndef CONFIG_SMP
  414. /*
  415. * Must not happen on UP:
  416. */
  417. SPIN_BUG_ON(!ret, lock, "trylock failure on UP");
  418. #endif
  419. return ret;
  420. }
  421. void do_raw_spin_unlock(raw_spinlock_t *lock)
  422. {
  423. debug_spin_unlock(lock);
  424. arch_spin_unlock(&lock->raw_lock);
  425. }
  426. static void rwlock_bug(rwlock_t *lock, const char *msg)
  427. {
  428. if (!debug_locks_off())
  429. return;
  430. printk(KERN_EMERG "BUG: rwlock %s on CPU#%d, %s/%d, %p\n",
  431. msg, raw_smp_processor_id(), current->comm,
  432. task_pid_nr(current), lock);
  433. dump_stack();
  434. }
  435. #define RWLOCK_BUG_ON(cond, lock, msg) if (unlikely(cond)) rwlock_bug(lock, msg)
  436. void do_raw_read_lock(rwlock_t *lock)
  437. {
  438. RWLOCK_BUG_ON(lock->magic != RWLOCK_MAGIC, lock, "bad magic");
  439. arch_read_lock(&lock->raw_lock);
  440. }
  441. int do_raw_read_trylock(rwlock_t *lock)
  442. {
  443. int ret = arch_read_trylock(&lock->raw_lock);
  444. #ifndef CONFIG_SMP
  445. /*
  446. * Must not happen on UP:
  447. */
  448. RWLOCK_BUG_ON(!ret, lock, "trylock failure on UP");
  449. #endif
  450. return ret;
  451. }
  452. void do_raw_read_unlock(rwlock_t *lock)
  453. {
  454. RWLOCK_BUG_ON(lock->magic != RWLOCK_MAGIC, lock, "bad magic");
  455. arch_read_unlock(&lock->raw_lock);
  456. }
  457. static inline void debug_write_lock_before(rwlock_t *lock)
  458. {
  459. RWLOCK_BUG_ON(lock->magic != RWLOCK_MAGIC, lock, "bad magic");
  460. RWLOCK_BUG_ON(lock->owner == current, lock, "recursion");
  461. RWLOCK_BUG_ON(lock->owner_cpu == raw_smp_processor_id(),
  462. lock, "cpu recursion");
  463. }
  464. static inline void debug_write_lock_after(rwlock_t *lock)
  465. {
  466. WRITE_ONCE(lock->owner_cpu, raw_smp_processor_id());
  467. WRITE_ONCE(lock->owner, current);
  468. }
  469. static inline void debug_write_unlock(rwlock_t *lock)
  470. {
  471. RWLOCK_BUG_ON(lock->magic != RWLOCK_MAGIC, lock, "bad magic");
  472. RWLOCK_BUG_ON(lock->owner != current, lock, "wrong owner");
  473. RWLOCK_BUG_ON(lock->owner_cpu != raw_smp_processor_id(),
  474. lock, "wrong CPU");
  475. WRITE_ONCE(lock->owner, SPINLOCK_OWNER_INIT);
  476. WRITE_ONCE(lock->owner_cpu, -1);
  477. }
  478. void do_raw_write_lock(rwlock_t *lock)
  479. {
  480. debug_write_lock_before(lock);
  481. arch_write_lock(&lock->raw_lock);
  482. debug_write_lock_after(lock);
  483. }
  484. int do_raw_write_trylock(rwlock_t *lock)
  485. {
  486. int ret = arch_write_trylock(&lock->raw_lock);
  487. if (ret)
  488. debug_write_lock_after(lock);
  489. #ifndef CONFIG_SMP
  490. /*
  491. * Must not happen on UP:
  492. */
  493. RWLOCK_BUG_ON(!ret, lock, "trylock failure on UP");
  494. #endif
  495. return ret;
  496. }
  497. void do_raw_write_unlock(rwlock_t *lock)
  498. {
  499. debug_write_unlock(lock);
  500. arch_write_unlock(&lock->raw_lock);
  501. }