How to prevent chatty expired

5,654 views
Skip to first unread message

satur9nine

unread,
Oct 23, 2019, 10:52:59 AM10/23/19
to android-platform
We are a device builder. On our devices we see a large number of logs being expired in logcat which makes it difficult to debug applications running on our devices.

10-21 10:07:38.731  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:07:41.734  8908  8930 I SetupWizard: before updateTime
10-21 10:07:42.341  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:07:45.343  8908  8930 I SetupWizard: before updateTime
10-21 10:07:45.924  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:07:48.927  8908  8930 I SetupWizard: before updateTime
10-21 10:07:48.929  8891  9862 I chatty  : uid=1000(system) Binder:8891_9 expire 63 lines
10-21 10:07:48.932  8891  8942 I chatty  : uid=1000(system) pool-2-thread-1 expire 24 lines
10-21 10:07:49.479  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:07:52.482  8908  8930 I SetupWizard: before updateTime
10-21 10:07:53.079  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:07:56.082  8908  8930 I SetupWizard: before updateTime
10-21 10:07:56.665  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:07:59.667  8908  8930 I SetupWizard: before updateTime
10-21 10:08:00.260  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:08:00.573  1341  1487 I sysui_multi_action: [757,1093,758,4,793,21985,1094,9437184,1095,4]
10-21 10:08:03.263  8908  8930 I SetupWizard: before updateTime
10-21 10:08:03.264  8891  9862 I chatty  : uid=1000(system) Binder:8891_9 expire 48 lines
10-21 10:08:03.814  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:08:06.817  8908  8930 I SetupWizard: before updateTime
10-21 10:08:06.821  8891  8942 I chatty  : uid=1000(system) pool-2-thread-1 expire 15 lines
10-21 10:08:06.844  1214  1365 I chatty  : uid=1000(system) Binder:1214_4 expire 4 lines
10-21 10:08:07.409  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:08:10.411  8908  8930 I SetupWizard: before updateTime
10-21 10:08:11.006  8908  8930 I SetupWizard: after updateTime, success=false
10-21 10:08:14.009  8908  8930 I SetupWizard: before updateTime
10-21 10:08:14.011  8891  9862 I chatty  : uid=1000(system) Binder:8891_9 expire 50 lines

How can we prevent these expirations? We are free to modify the Android platform in any way necessary.

Inspecting the logd source code has not led to any obvious solutions. And I do not see how or why we would be hitting any kind of limit. As you can tell from the above the number of logs being emitted is only about 150 over the course of 36 seconds. 

Regards,
Jacob

satur9nine

unread,
Oct 24, 2019, 10:46:47 AM10/24/19
to android-platform
Diane Hackborn helped me solve this problem at Dev Summit 2019.

Logd uses a prune filter to remove old entries from the log rather than simply dropping the oldest entries like a normal FIFO.

The default filter is "~! ~1000/!" (very unusual syntax!) which is described in logd/README.property:

persist.logd.filter        string        Pruning filter to optimize content.
                                         At runtime use: logcat -P "<string>"
ro.logd.filter       string "~! ~1000/!" default for persist.logd.filter.
                                         This default means to prune the
                                         oldest entries of chattiest UID, and
                                         the chattiest PID of system
                                         (1000, or AID_SYSTEM).

The fix is to add the following to your base.mk or similar build script:

PRODUCT_PROPERTY_OVERRIDES += \
    ro.logd.filter=disable

See https://android.googlesource.com/platform/system/core/+/refs/heads/master/logd/LogWhiteBlackList.cpp for the code that controls this. Empty string apparently causes property_get to use the default which is I guess why they look for the magic string "disable".

Doing this will return logd to a typical FIFO and you should no longer see "expire" messages in logcat. You will still see "identical" though if there are identical messages.

Jacob

Andrew Esh

unread,
Oct 24, 2019, 1:59:03 PM10/24/19
to android-platform
Reply all
Reply to author
Forward
0 new messages