[Android systrace系列] systrace时间戳与手机时间的对应关系

一般用systrace分析问题,我们直接查看关注的流程即可。

有时logcat提供了重要的信息,但这些信息没有用systrace log输出。

如果我们能将systrace时间与手机时间对应起来,就不用添加systrace log重新编译手机ROM了。

----------------------------------------------------------------------------------

这篇文章的小目标:

1. 计算systrace时间与手机时间的对应关系

2. 在自己的代码中添加systrace log

---------------------------------------------------

 

这里存在三个时间戳,

1)systrace时间轴上的时间,时间轴从0开始算起,以毫秒为单位

2)kernel 时间,记录kernel开始启动后流逝的时间,以秒为单位

3)系统时钟,显示当时几点钟,也就是system log的时间

 

要找到systrace时间与kernel时间的对应关系,非常简单,只需要以纯文本方式打开systrace的html文件,搜"TIMESTAMP  FUNCTION",第一句log显示的kernel时间,就对应着systrace时间轴的起始时间。

我们用一个真实的trace文件来算一下,下面是第一句log

<...>-8634  (-----) [001] ...1 944990.442341: tracing_mark_write: trace_event_clock_sync: parent_ts=80241.648438

这里的944990.442341是kernel log时间,同时也是systrace时间轴的起始时间。

 

我们用下面截图,算出DrawFrame流程的开始时的kernel时间,由于单位不同,这里systrace时间戳需要转换单位为秒。

 

我们用纯文本打开trace文件看看是不是:

RenderThread-8555  ( 8508) [002] ...1 944997.124754: tracing_mark_write: B|8508|DrawFrame

这里的误差是毫秒以内的,一般足够了。

 

 

我们再来找kernel log时间与系统system log时间的对应关系

每个厂商或许都有各自的log对照,这里使用一个浅显的方法来对照。

思路是在app中以systrace log的方式,输出当前系统时间,再用systrace来看。

首先要介绍添加systrace log的方法,按照惯例,我引用官方文档:

https://developer.android.google.cn/studio/profile/systrace/custom-events?hl=zh-cn

这个文档,说明了在自己代码添加systrace log,测量耗时的方法。

 

看完如何加log的文档,言归正传,我们在Hello world app上加上一个按钮,一点按钮就打systrace log,我们这里用Time align作为关键字。

package nothing.example;

import android.os.Bundle;
import android.os.Trace;
import android.view.View;
import android.widget.Button;

import androidx.appcompat.app.AppCompatActivity;

public class MainActivity extends AppCompatActivity {

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);

        Button TimeAlignButton = findViewById(R.id.TimeAlignButton);
        TimeAlignButton.setOnClickListener(new View.OnClickListener() {
            @Override
            public void onClick(View view) {
                long totalMilliSeconds = System.currentTimeMillis();
                long totalSeconds = totalMilliSeconds / 1000;

                long currentSecond = totalSeconds % 60;

                long totalMinutes = totalSeconds / 60;
                long currentMinute = totalMinutes % 60;

                //中国时区是东八区,所以+8
                long totalHour = totalMinutes / 60 + 8;
                long currentHour = totalHour % 24;

                long ms = totalMilliSeconds % 1000;

                Trace.beginSection("Time align " + currentHour + ":" + currentMinute + ":" + currentSecond + "." + ms);
                Trace.endSection();
            }
        });
    }
}

 

接下来我们抓取点击按钮操作的systrace,按照 [Android systrace系列] systrace入门第一式 的方法,把app输出的systrace log抓到。

需要留心的是,因为这里需要抓app的systrace log,所以需要userdebug版本的手机。

python systrace.py -o mynewtrace.html -a nothing.example

纯文本打开mynewtrace.html,搜索Time align,kernel时间1434.981241和系统时钟15:11:32.537就对上了。

nothing.exampl-7676  ( 7676) [000] ...1  1434.981241: tracing_mark_write: B|7676|Time align 15:11:32.537

 

小目标,完成。

 

 

转载请注明出处:https://www.cnblogs.com/zzcperf/p/14008147.html

posted @ 2020-11-29 21:31  zzc1024  阅读(115)  评论(0编辑  收藏