Android -- bug记录：SharePreferences导致的卡顿问题

最新推荐文章于 2024-03-20 14:53:17 发布

Regina Mills

最新推荐文章于 2024-03-20 14:53:17 发布

阅读量337

点赞数

文章标签： android bug java

本文链接：https://blog.csdn.net/weixin_44790378/article/details/131110549

版权

问题描述

在媒体播放界面,切换至蓝牙音乐，界面出现卡顿，卡了几秒才切换成功

定位问题

08-08 00:02:05.113  2735  2735 I Choreographer: Skipped 286 frames!  The application may be doing too much work on its main thread.

在log中找到了一个关键点，这句log是提示我们在主线程做了耗时操作，导致掉了286帧 !!!∑(°Д°ノ)ノ
于是顺藤摸瓜找到对应卡顿的线程，搜索该线程打印的日志，定位到卡顿的时间段，位于02:00至02:05，卡顿约五秒左右，线程才有继续运行打印的log。

08-08 00:02:00.326  2735  2735 I BtMusicService: onStartCommand: 
08-08 00:02:00.328  2735  2735 I BtMusicService: Local BT Address: xxxxx
08-08 00:02:00.328  2735  2735 I SharedPreferencesUtil: get: key = isPlaying, value = false
08-08 00:02:00.328  2735  2735 D BtMusicService: getMemoryPlayStatus: result:false
08-08 00:02:05.062  2735  2735 D SharedPreferencesImpl: Time required to fsync 一个文件名.xml: [<1: 0, <2: 0, <4: 0, <8: 17, <16: 11, <32: 5, <64: 2, <128: 1, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 1, <16384: 0, >=16384: 0]
08-08 00:02:05.062  2735  2735 D QueuedWork: waited: [<1: 0, <2: 2, <4: 0, <8: 4, <16: 8, <32: 1, <64: 0, <128: 0, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 1, <16384: 0, >=16384: 0]
08-08 00:02:05.062  2735  2735 I BTMusicController: onServiceConnected:

其中有一项特别可疑的地方，出现了SharedPreferencesImpl提示的操作，还有QueuedWork在等待完成，当然我也不知道他到底在等什么，在anr日志中也没有有效的信息ヽ(＊｀Д´)ノ

08-08 00:02:05.062  2735  2735 D SharedPreferencesImpl: Time required to fsync 一个文件名.xml: [<1: 0, <2: 0, <4: 0, <8: 17, <16: 11, <32: 5, <64: 2, <128: 1, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 1, <16384: 0, >=16384: 0]
08-08 00:02:05.062  2735  2735 D QueuedWork: waited: [<1: 0, <2: 2, <4: 0, <8: 4, <16: 8, <32: 1, <64: 0, <128: 0, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 1, <16384: 0, >=16384: 0]

通过多次复现发现每次都卡在了同一个地方，于是从同步的文件出发《一个文件名.xml》，在代码中定位到调用的方法,是在子线程中调用的 saveMemoryOfFragmentName()

08-08 00:02:00.281  2735  3253 D MediaManager|MediaManagerFragment: handleChildMessage =3
08-08 00:02:00.281  2735  3253 D MediaManager|MediaManagerFragment: saveMemoryOfFragmentName

具体的操作是使用了 SharePreferences 的 apply() 方法对内存进行操作。

    public static void saveString(Context context, String key, String value) {
        sharedPreferences(context).edit().putString(key, value).apply();
    }

于是关于一个本次问题发生的重要点：

子线程IO就一定不会阻塞主线程吗？

问题分析

首先我们先来了解一下SharedPreferences是什么，简单来说就是在应用中通常做一些简单数据的持久化缓存，以键值对（key-value）的方式保存数据，xml文件保存在/data/data/shared_prefs目录下。

apply() 方法分析

SharedPreferences的确是线程安全的，apply()的内部实现将I/O操作交给了子线程，可以说其本身是没有问题的，在apply()方法中，首先会创建一个等待锁，执行一个异步任务，最终这异步任务的执行是在QueuedWork.queue(writeToDiskRunnable, !isFromSyncCommit)方法中，当文件更新完毕后会释放锁。

        public void apply() {
            final long startTime = System.currentTimeMillis();
            final MemoryCommitResult mcr = this.commitToMemory();
            final Runnable awaitCommit = new Runnable() {
                public void run() {
                    try {
                        mcr.writtenToDiskLatch.await();
                    } catch (InterruptedException var2) {
                    }

                }
            };
            QueuedWork.addFinisher(awaitCommit);
            Runnable postWriteRunnable = new Runnable() {
                public void run() {
                    awaitCommit.run();
                    QueuedWork.removeFinisher(awaitCommit);
                }
            };
            SharedPreferencesImpl.this.enqueueDiskWrite(mcr, postWriteRunnable);
            this.notifyListeners(mcr);
        }

在上面提到apply()中会创建一个等待锁（awaitCommit 中包含了一个等待锁），此时遇到了本次卡顿的关键原因：主线程正是在等待这把锁

如果异步任务执行时间过长，当ActvityThread执行了handleStopActivity或者handleServiceArgs或者handlePauseActivity 等方法的时候都会调用QueuedWork.waitToFinish()方法,而此方法中会在异步任务执行完成前一直阻塞住主线程，所以卡顿问题就产生了
以上分析来源： https://www.jianshu.com/p/40e42da910e2

在代码设计中，用户切换音源的时候会unbind掉其他音源的service，再切回来的时候会再次bindService，此次导致的卡顿正是出现在反复切源的时候。

问题到这里就已经基本确定了卡顿原因，至于解决的具体方法在百度上搜到的是清空等待队列，但由于调用的大哥说他模块好像用SharePreferences存的这个东西也没有用，所以就直接把调用的代码去掉了，然后就没有卡顿的问题了，完结撒花 ‧★,::‧(￣▽￣)/‧:‧°★*

以下延展一下service的生命周期

Service的生命周期

但资料里的handleServiceArgs大多数出现于使用startService开启Service，而不是bindService，其实我也不太确定到底有没有调用到QueuedWork.waitToFinish()方法导致线程等待，于是不得不提到Service的生命周期，然后我就开始在bindService中试图找到handleServiceArgs的身影。

从源码上分析使用startService启动Service很容易可以看出调用到了handleServiceArgs方法，那么到底使用bindService启动Service有没有调用到handleServiceArgs方法呢？
源码分析参考：
https://www.jianshu.com/p/c4927c0b80a9
https://blog.csdn.net/xingzhong128/article/details/80026364
ContextImpl里的各种bindService最终调用的是bindServiceCommon这个方法的实现，

    public boolean bindService(Intent var1, ServiceConnection var2, int var3) {
        this.warnIfCallingFromSystemProcess();
        return this.bindServiceCommon(var1, var2, var3, this.mMainThread.getHandler(), Process.myUserHandle());
    }

以下省略掉了其他的代码，关注于调用了ActivityManagerService的bindService方法

    private boolean bindServiceCommon(Intent var1, ServiceConnection var2, int var3, Handler var4, UserHandle var5) {
        if (var2 == null) {
            ...
        } else if (this.mPackageInfo != null) {
            ....
            try {
               ....
                }
                ...
                int var8 = ActivityManager.getService().bindService(this.mMainThread.getApplicationThread(), this.getActivityToken(), var1, var1.resolveTypeIfNeeded(this.getContentResolver()), var6, var3, this.getOpPackageName(), var5.getIdentifier());
				...
            } catch (RemoteException var9) {
                ...
            }
        } else {
            ...
        }
    }

ActivityManagerService的bindService

核心就是调用了bindServiceLocked方法。

 public int bindService(IApplicationThread caller, IBinder token, Intent service,
            String resolvedType, IServiceConnection connection, int flags, String callingPackage,
            int userId) throws TransactionTooLargeException {
...
        synchronized(this) {
            return mServices.bindServiceLocked(caller, token, service,
                    resolvedType, connection, flags, callingPackage, userId);
        }
    }

在bindServiceLocked中有一个realStartServiceLocked方法

*  此处省略bindServiceLocked代码(눈‸눈)  *

bringUpServiceLocked中调用realStartServiceLocked方法

    private String bringUpServiceLocked(...){
		if (r.app != null && r.app.thread != null) {
            sendServiceArgsLocked(r, execInFg, false);
            return null;
        }
        if (!isolated) {
...
            if (app != null && app.thread != null) {
                try {
                    //调用realStartServiceLocked
                    realStartServiceLocked(r, app, execInFg);
                    return null;
                } 
            }
        }
        return null;
    }

realStartServiceLocked方法中调用了sendServiceArgsLocked方法

private final void realStartServiceLocked(ServiceRecord r,
        ProcessRecord app, boolean execInFg) throws RemoteException {
...
        app.thread.scheduleCreateService(r, r.serviceInfo,
                mAm.compatibilityInfoForPackageLocked(r.serviceInfo.applicationInfo),
                app.repProcState); //创建service
...
    sendServiceArgsLocked(r, execInFg, true); //添加service的启动参数
...
}

sendServiceArgsLocked方法调用ActivityThread的scheduleServiceArgs方法

private final void sendServiceArgsLocked(ServiceRecord r, boolean execInFg,
        boolean oomAdjusted) throws TransactionTooLargeException {
...
        r.app.thread.scheduleServiceArgs(r, slice);
        //该方法中会sendMessage(H.SERVICE_ARGS, s); 在HandleMedssage搜索SERVICE_ARGS可找到handleServiceArgs方法！
...
}

然后经历一系列的调用之后，终于看到了我们想看到的handleServiceArgs‼ ψ(｀∇´)ψ

   public void handleMessage(Message msg) {
...
            case SERVICE_ARGS:
                if (Trace.isTagEnabled(Trace.TRACE_TAG_ACTIVITY_MANAGER)) {
...
                }
                handleServiceArgs((ServiceArgsData)msg.obj);
...
    }

以下是handleServiceArgs的具体操作,重点在于onStartCommand以及QueuedWork.waitToFinish()

//ActivityThread.java
private void handleServiceArgs(ServiceArgsData data) {
    Service s = mServices.get(data.token);
    if (s != null) {
        try {
            if (data.args != null) {
...
            }
            int res;
            if (!data.taskRemoved) {
                //这里取到service中onStartCommand方法的返回值
                res = s.onStartCommand(data.args, data.flags, data.startId); 
            } else {
...
            }

            QueuedWork.waitToFinish();

            try {
...
            } catch (RemoteException e) {
...
            }
        } catch (Exception e) {
...
        }
    }
}

在日志中也可以体现出线程运行完onStartCommand方法都就卡住了，与分析的现象一致，确认卡顿是该问题造成的

08-08 00:02:00.326  2735  2735 I BtMusicService: onStartCommand: 
08-08 00:02:00.328  2735  2735 I onStartCommand中方法的操作
08-08 00:02:00.328  2735  2735 I onStartCommand中方法的操作
08-08 00:02:00.328  2735  2735 D onStartCommand中最后一个方法执行完毕
08-08 00:02:05.062  2735  2735 D SharedPreferencesImpl: Time required to fsync 一个文件名.xml: [<1: 0, <2: 0, <4: 0, <8: 17, <16: 11, <32: 5, <64: 2, <128: 1, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 1, <16384: 0, >=16384: 0]
08-08 00:02:05.062  2735  2735 D QueuedWork: waited: [<1: 0, <2: 2, <4: 0, <8: 4, <16: 8, <32: 1, <64: 0, <128: 0, <256: 0, <512: 0, <1024: 0, <2048: 0, <4096: 0, <8192: 1, <16384: 0, >=16384: 0]