Re: [RFC] simple_lmk: Introduce Simple Low Memory Killer for Android
From: Sultan Alsawaf
Date: Mon May 13 2019 - 12:47:37 EST
On Fri, May 10, 2019 at 05:10:25PM +0200, Oleg Nesterov wrote:
> I am starting to think I am ;)
>
> If you have task1 != task2 this code
>
> task_lock(task1);
> task_lock(task2);
>
> should trigger print_deadlock_bug(), task1->alloc_lock and task2->alloc_lock are
> the "same" lock from lockdep pov, held_lock's will have the same hlock_class().
Okay, I've stubbed out debug_locks_off(), and lockdep is now complaining about a
bunch of false positives so it is _really_ enabled this time. I grepped for
lockdep last time to try and find a concise way to show over email that lockdep
didn't complain, but that backfired. Here is better evidence:
taimen:/ # dmesg | grep simple_lmk
[ 58.349917] simple_lmk: Killing droid.deskclock with adj 906 to free 47548 KiB
[ 58.354748] simple_lmk: Killing .android.dialer with adj 906 to free 36576 KiB
[ 58.355030] simple_lmk: Killing rbandroid.sleep with adj 904 to free 50016 KiB
[ 58.582833] simple_lmk: Killing oadcastreceiver with adj 904 to free 43044 KiB
[ 58.587731] simple_lmk: Killing .apps.wellbeing with adj 902 to free 48128 KiB
[ 58.588084] simple_lmk: Killing android.carrier with adj 902 to free 43636 KiB
[ 58.671857] simple_lmk: Killing ndroid.keychain with adj 902 to free 39992 KiB
[ 58.675622] simple_lmk: Killing gs.intelligence with adj 900 to free 49572 KiB
[ 58.675770] simple_lmk: Killing le.modemservice with adj 800 to free 41976 KiB
[ 58.762060] simple_lmk: Killing ndroid.settings with adj 700 to free 74708 KiB
[ 58.763238] simple_lmk: Killing roid.apps.turbo with adj 700 to free 54660 KiB
[ 58.873337] simple_lmk: Killing d.process.acore with adj 700 to free 48540 KiB
[ 58.873513] simple_lmk: Killing d.process.media with adj 500 to free 46188 KiB
[ 58.873713] simple_lmk: Killing putmethod.latin with adj 200 to free 67304 KiB
[ 59.014046] simple_lmk: Killing android.vending with adj 201 to free 54900 KiB
[ 59.017623] simple_lmk: Killing rak.mibandtools with adj 201 to free 44552 KiB
[ 59.018423] simple_lmk: Killing eport.trebuchet with adj 100 to free 106208 KiB
[ 59.223633] simple_lmk: Killing id.printspooler with adj 900 to free 39664 KiB
[ 59.223762] simple_lmk: Killing gle.android.gms with adj 100 to free 64176 KiB
[ 70.955204] simple_lmk: Killing .apps.translate with adj 906 to free 47564 KiB
[ 70.955633] simple_lmk: Killing cloudprint:sync with adj 906 to free 31932 KiB
[ 70.955787] simple_lmk: Killing oid.apps.photos with adj 904 to free 50204 KiB
[ 71.060789] simple_lmk: Killing ecamera.android with adj 906 to free 32232 KiB
[ 71.061074] simple_lmk: Killing webview_service with adj 906 to free 26028 KiB
[ 71.061199] simple_lmk: Killing com.whatsapp with adj 904 to free 49484 KiB
[ 71.190625] simple_lmk: Killing rbandroid.sleep with adj 906 to free 54724 KiB
[ 71.190775] simple_lmk: Killing android.vending with adj 906 to free 39848 KiB
[ 71.191303] simple_lmk: Killing m.facebook.orca with adj 904 to free 72296 KiB
[ 71.342042] simple_lmk: Killing droid.deskclock with adj 902 to free 49284 KiB
[ 71.342240] simple_lmk: Killing .apps.wellbeing with adj 900 to free 47632 KiB
[ 71.342529] simple_lmk: Killing le.modemservice with adj 800 to free 33648 KiB
[ 71.482391] simple_lmk: Killing d.process.media with adj 800 to free 40676 KiB
[ 71.482511] simple_lmk: Killing rdog.challegram with adj 700 to free 71920 KiB
taimen:/ #
The first simple_lmk message appears at 58.349917. And based on the timestamps,
it's clear that simple_lmk called task_lock() for multiple different tasks,
which is the pattern you think should cause lockdep to complain. But here is the
full dmesg starting from that point:
[ 58.349917] simple_lmk: Killing droid.deskclock with adj 906 to free 47548 KiB
[ 58.354748] simple_lmk: Killing .android.dialer with adj 906 to free 36576 KiB
[ 58.355030] simple_lmk: Killing rbandroid.sleep with adj 904 to free 50016 KiB
[ 58.432654] binder_alloc: 2284: binder_alloc_buf failed to map pages in userspace, no vma
[ 58.432671] binder: 1206:1218 transaction failed 29189/-3, size 76-0 line 3189
[ 58.582833] simple_lmk: Killing oadcastreceiver with adj 904 to free 43044 KiB
[ 58.587731] simple_lmk: Killing .apps.wellbeing with adj 902 to free 48128 KiB
[ 58.588084] simple_lmk: Killing android.carrier with adj 902 to free 43636 KiB
[ 58.590785] binder: undelivered transaction 58370, process died.
[ 58.671857] simple_lmk: Killing ndroid.keychain with adj 902 to free 39992 KiB
[ 58.675622] simple_lmk: Killing gs.intelligence with adj 900 to free 49572 KiB
[ 58.675770] simple_lmk: Killing le.modemservice with adj 800 to free 41976 KiB
[ 58.736678] binder: undelivered transaction 58814, process died.
[ 58.736733] binder: release 3099:3128 transaction 57832 in, still active
[ 58.736744] binder: send failed reply for transaction 57832 to 1876:3090
[ 58.736761] binder: undelivered TRANSACTION_COMPLETE
[ 58.736766] binder: undelivered transaction 58752, process died.
[ 58.762060] simple_lmk: Killing ndroid.settings with adj 700 to free 74708 KiB
[ 58.763238] simple_lmk: Killing roid.apps.turbo with adj 700 to free 54660 KiB
[ 58.863590] binder: release 1876:3089 transaction 58117 out, still active
[ 58.863606] binder: undelivered TRANSACTION_COMPLETE
[ 58.873337] simple_lmk: Killing d.process.acore with adj 700 to free 48540 KiB
[ 58.873513] simple_lmk: Killing d.process.media with adj 500 to free 46188 KiB
[ 58.873713] simple_lmk: Killing putmethod.latin with adj 200 to free 67304 KiB
[ 59.014046] simple_lmk: Killing android.vending with adj 201 to free 54900 KiB
[ 59.017623] simple_lmk: Killing rak.mibandtools with adj 201 to free 44552 KiB
[ 59.018423] simple_lmk: Killing eport.trebuchet with adj 100 to free 106208 KiB
[ 59.028460] binder: 1206:1206 transaction failed 29189/-22, size 100-0 line 3052
[ 59.142592] binder_alloc: 2814: binder_alloc_buf, no vma
[ 59.142620] binder: 1206:1218 transaction failed 29189/-3, size 76-0 line 3189
[ 59.223633] simple_lmk: Killing id.printspooler with adj 900 to free 39664 KiB
[ 59.223762] simple_lmk: Killing gle.android.gms with adj 100 to free 64176 KiB
[ 59.540176] binder: undelivered transaction 59447, process died.
[ 59.540763] binder: undelivered transaction 59446, process died.
[ 59.815404] binder: 1206:3140 transaction failed 29189/0, size 12-0 line 2992
[ 59.815418] binder: send failed reply for transaction 58117, target dead
[ 60.977609] binder: 2105:2308 transaction failed 29189/-22, size 168-0 line 3052
[ 63.040202] FG: fg_get_battery_temp: batt temperature original:350, tuned:309
[ 63.040219] lge_battery: bm_watch_work: PRESENT:1, CHG_STAT:1, THM_STAT:2, BAT_TEMP:309, BAT_VOLT:4148182, VOTE_CUR:1000000, SET_CUR:1000000
[ 63.076086] msm-dwc3 a800000.ssusb: Avail curr from USB = 2
[ 63.077278] PMI: smblib_handle_switcher_power_ok: Weak charger detected: voting 500mA ICL
[ 63.080014] PMI: smblib_handle_switcher_power_ok: Reverse boost detected: voting 0mA to suspend input
[ 63.081886] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.093639] fts_touch 5-0049: [FTS] Received Charger Disconnected Event
[ 63.104656] healthd: battery l=100 v=4148 t=31.0 h=2 st=3 c=748 fc=3229000 cc=289 chg=
[ 63.122546] healthd: battery l=100 v=4148 t=31.0 h=2 st=3 c=748 fc=3229000 cc=289 chg=
[ 63.135620] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.156383] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.156897] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.160481] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.185029] healthd: battery l=100 v=4148 t=31.0 h=2 st=3 c=748 fc=3229000 cc=289 chg=
[ 63.189015] healthd: battery l=100 v=4148 t=31.0 h=2 st=3 c=748 fc=3229000 cc=289 chg=
[ 63.212484] lge_battery: bm_check_status: wake_unlocked: present[0] chg_state[2] vbus[0]
[ 63.213039] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.231096] FG: fg_get_battery_temp: batt temperature original:350, tuned:310
[ 63.233981] healthd: battery l=100 v=4148 t=31.0 h=2 st=3 c=748 fc=3229000 cc=289 chg=
[ 63.234663] msm-dwc3 a800000.ssusb: dwc3_msm_suspend: Calling suspend 1996
[ 63.249755] msm-dwc3 a800000.ssusb: DWC3 in low power mode
[ 63.250247] healthd: battery l=100 v=4148 t=31.0 h=2 st=3 c=748 fc=3229000 cc=289 chg=
[ 63.250430] android_work: sent uevent USB_STATE=DISCONNECTED
[ 63.294456] msm-dwc3 a800000.ssusb: Avail curr from USB = 0
[ 70.492114] binder: undelivered transaction 86938, process died.
[ 70.955204] simple_lmk: Killing .apps.translate with adj 906 to free 47564 KiB
[ 70.955633] simple_lmk: Killing cloudprint:sync with adj 906 to free 31932 KiB
[ 70.955787] simple_lmk: Killing oid.apps.photos with adj 904 to free 50204 KiB
[ 71.060789] simple_lmk: Killing ecamera.android with adj 906 to free 32232 KiB
[ 71.061074] simple_lmk: Killing webview_service with adj 906 to free 26028 KiB
[ 71.061199] simple_lmk: Killing com.whatsapp with adj 904 to free 49484 KiB
[ 71.164996] binder: undelivered transaction 87881, process died.
[ 71.190625] simple_lmk: Killing rbandroid.sleep with adj 906 to free 54724 KiB
[ 71.190775] simple_lmk: Killing android.vending with adj 906 to free 39848 KiB
[ 71.191303] simple_lmk: Killing m.facebook.orca with adj 904 to free 72296 KiB
[ 71.342042] simple_lmk: Killing droid.deskclock with adj 902 to free 49284 KiB
[ 71.342240] simple_lmk: Killing .apps.wellbeing with adj 900 to free 47632 KiB
[ 71.342529] simple_lmk: Killing le.modemservice with adj 800 to free 33648 KiB
[ 71.482391] simple_lmk: Killing d.process.media with adj 800 to free 40676 KiB
[ 71.482511] simple_lmk: Killing rdog.challegram with adj 700 to free 71920 KiB
No lockdep warnings!
Sultan