首页 > 其他分享 >分析ueventd Coldboot耗时问题

分析ueventd Coldboot耗时问题

时间：2024-08-27 21:08:14浏览次数：11  
标签：00 01 20 init ueventd 耗时 Coldboot action

安卓go平台启动时间发现如下ueventd耗时1.907s问题：

01-11 00:20:02.854     0     0 I init    : Parsing file /odm/etc/init...
01-11 00:20:02.854     0     0 E init    : Unable to open '/odm/etc/init': No such file or directory
01-11 00:20:02.854     0     0 I init    : processing action (early-init) from (/init.rc:14)
01-11 00:20:02.855     0     0 D SELinux : initialized (dev cgroup, type cgroup), uses genfs_contexts
01-11 00:20:02.856     0     0 I init    : starting service 'ueventd'...
01-11 00:20:02.857     0     0 W cgroup  : init (1) created nested cgroup for controller "memory" which has incomplete hierarchy support. Nested cgroups may change behavior in the future.
01-11 00:20:02.857     0     0 W cgroup  : "memory" requires setting use_hierarchy to 1 on the root
01-11 00:20:02.857     0     0 I init    : processing action (early-init) from (/vendor/etc/init/hw/init.qcom.rc:35)
01-11 00:20:02.858     0     0 I init    : processing action (early-init) from (/vendor/etc/init/hw/init.target.rc:32)
01-11 00:20:02.859     0     0 I init    : processing action (wait_for_coldboot_done) from (<Builtin Action>:0)
01-11 00:20:02.861     0     0 I ueventd : ueventd started!
01-11 00:20:02.861     0     0 I ueventd : Parsing file /ueventd.rc...
01-11 00:20:02.867     0     0 I ueventd : Parsing file /vendor/ueventd.rc...
01-11 00:20:02.871     0     0 I ueventd : Parsing file /odm/ueventd.rc...
01-11 00:20:02.871     0     0 E ueventd : Unable to open '/odm/ueventd.rc': No such file or directory
01-11 00:20:02.871     0     0 I ueventd : Parsing file /ueventd.qcom.rc...
01-11 00:20:02.871     0     0 E ueventd : Unable to open '/ueventd.qcom.rc': No such file or directory
01-11 00:20:02.881     0     0 I selinux : SELinux: Loaded file_contexts
01-11 00:20:03.137     0     0 I chatty  : uid=0(root) logd identical 4 lines
01-11 00:20:03.168     0     0 I selinux : SELinux: Loaded file_contexts
01-11 00:20:04.789     0     0 I ueventd : Coldboot took 1.907 seconds
01-11 00:20:04.791     0     0 I init    : Command 'wait_for_coldboot_done' action=wait_for_coldboot_done (<Builtin Action>:0) returned 0 took 1932ms.
01-11 00:20:04.792     0     0 I init    : processing action (mix_hwrng_into_linux_rng) from (<Builtin Action>:0)

对应code在system/core/init/ueventd.cpp：

void ColdBoot::Run() {
    android::base::Timer cold_boot_timer;

    RegenerateUevents();

    ForkSubProcesses();

    DoRestoreCon();

    WaitForSubProcesses();

    close(open(COLDBOOT_DONE, O_WRONLY | O_CREAT | O_CLOEXEC, 0000));
    LOG(INFO) << "Coldboot took " << cold_boot_timer.duration().count() / 1000.0f << " seconds";
}

在ueventd main中运行：

int ueventd_main(int argc, char** argv) {
    /*  
     * init sets the umask to 077 for forked processes. We need to
     * create files with exact permissions, without modification by
     * the umask.
     */
    umask(000);

    InitKernelLogging(argv);

    LOG(INFO) << "ueventd started!";

    selinux_callback cb; 
    cb.func_log = selinux_klog_callback;
    selinux_set_callback(SELINUX_CB_LOG, cb);

    DeviceHandler device_handler = CreateDeviceHandler();
    UeventListener uevent_listener;

    if (access(COLDBOOT_DONE, F_OK) != 0) {
        ColdBoot cold_boot(uevent_listener, device_handler);
        cold_boot.Run();
    }

init.rc会触发ueventd启动：

on early-init
    ...
    start ueventd

system/core/init/init.cpp会解析init.rc:

int main(int argc, char** argv) {
    ...
    std::string bootscript = GetProperty("ro.boot.init_rc", ""); 
    if (bootscript.empty()) {
        parser.ParseConfig("/init.rc");
        parser.set_is_system_etc_init_loaded(
                parser.ParseConfig("/system/etc/init"));
        parser.set_is_vendor_etc_init_loaded(
                parser.ParseConfig("/vendor/etc/init"));
        parser.set_is_odm_etc_init_loaded(parser.ParseConfig("/odm/etc/init"));
    } else {
        parser.ParseConfig(bootscript);
        parser.set_is_system_etc_init_loaded(true);
        parser.set_is_vendor_etc_init_loaded(true);
        parser.set_is_odm_etc_init_loaded(true);
    }

解析完后会继续触发boot actions，首先是early-init：

am.QueueEventTrigger("early-init");

// Queue an action that waits for coldboot done so we know ueventd has set up all of /dev...
am.QueueBuiltinAction(wait_for_coldboot_done_action, "wait_for_coldboot_done");
// ... so that we can start queuing up actions that require stuff from /dev.
am.QueueBuiltinAction(mix_hwrng_into_linux_rng_action, "mix_hwrng_into_linux_rng");
am.QueueBuiltinAction(set_mmap_rnd_bits_action, "set_mmap_rnd_bits");
am.QueueBuiltinAction(set_kptr_restrict_action, "set_kptr_restrict");
am.QueueBuiltinAction(keychord_init_action, "keychord_init");
am.QueueBuiltinAction(console_init_action, "console_init");

// Trigger all the boot actions to get us started.
am.QueueEventTrigger("init");

builtin action入队看下:

void ActionManager::QueueEventTrigger(const std::string& trigger) {
    event_queue_.emplace(trigger);
}

void Action::AddCommand(BuiltinFunction f, const std::vector<std::string>& args, int line) {
    commands_.emplace_back(f, args, line);
}

void ActionManager::QueueBuiltinAction(BuiltinFunction func, const std::string& name) {
    auto action = std::make_unique<Action>(true, "<Builtin Action>", 0); 
    std::vector<std::string> name_vector{name};

    if (!action->InitSingleTrigger(name)) {
        return;
    }   

    action->AddCommand(func, name_vector, 0); 

    event_queue_.emplace(action.get()); //也queue event
    actions_.emplace_back(std::move(action));
}

由上可见，最先处理action是early-init，然后是wait_for_coldboot_done：

入队以后会执行命令了：

while (true) {
    // By default, sleep until something happens.
    int epoll_timeout_ms = -1;

    if (do_shutdown && !shutting_down) {
        do_shutdown = false;
        if (HandlePowerctlMessage(shutdown_command)) {
            shutting_down = true;
        }    
    }    

    if (!(waiting_for_prop || sm.IsWaitingForExec())) {
        am.ExecuteOneCommand();
    }

am执行命令接口，先从queue里找到最先入队action，就是early-init了：

void ActionManager::ExecuteOneCommand() {
    // Loop through the event queue until we have an action to execute
    while (current_executing_actions_.empty() && !event_queue_.empty()) {
        for (const auto& action : actions_) {
            if (std::visit([&action](const auto& event) { return action->CheckEvent(event); },
                           event_queue_.front())) {
                current_executing_actions_.emplace(action.get());
            }   
        }   
        event_queue_.pop();
    }   

    if (current_executing_actions_.empty()) {
        return;
    }   

    auto action = current_executing_actions_.front();

    if (current_command_ == 0) {
        std::string trigger_name = action->BuildTriggersString();
        LOG(INFO) << "processing action (" << trigger_name << ") from (" << action->filename()
                  << ":" << action->line() << ")";
    }   

    action->ExecuteOneCommand(current_command_);

action的执行命令，超过50ms才会报个log，从log看显然early-init没有，是wait_for_coldboot_done超时了：

void Action::ExecuteCommand(const Command& command) const {
    android::base::Timer t;
    int result = command.InvokeFunc(); //这里

    auto duration = t.duration();
    // Any action longer than 50ms will be warned to user as slow operation
    if (duration > 50ms || android::base::GetMinimumLogSeverity() <= android::base::DEBUG) {
        std::string trigger_name = BuildTriggersString();
        std::string cmd_str = command.BuildCommandString();

        LOG(INFO) << "Command '" << cmd_str << "' action=" << trigger_name << " (" << filename_
                  << ":" << command.line() << ") returned " << result << " took "
                  << duration.count() << "ms.";
    }
}

int Command::InvokeFunc() const {
    std::vector<std::string> expanded_args;
    expanded_args.resize(args_.size());
    expanded_args[0] = args_[0];
    for (std::size_t i = 1; i < args_.size(); ++i) {
        if (!expand_props(args_[i], &expanded_args[i])) {
            LOG(ERROR) << args_[0] << ": cannot expand '" << args_[i] << "'";
            return -EINVAL;
        }   
    }   

    return func_(expanded_args);
}

这里的func_就先是do_start了，这个command就是一开始解析init.rc时add command了:

bool Action::AddCommand(const std::vector<std::string>& args, int line, std::string* err) {
    if (!function_map_) {
        *err = "no function map available";
        return false;
    }

    auto function = function_map_->FindFunction(args, err); //从function map找到start命令对应的func:do_start
    if (!function) {
        return false;
    }

    AddCommand(function, args, line);
    return true;
}

bool ActionParser::ParseLineSection(std::vector<std::string>&& args, int line, std::string* err) {
    return action_ ? action_->AddCommand(std::move(args), line, err) : false;
}

function map里start命令对应的接口是do_start:

const BuiltinFunctionMap::Map& BuiltinFunctionMap::map() const {
    constexpr std::size_t kMax = std::numeric_limits<std::size_t>::max();
    // clang-format off
    static const Map builtin_functions = {
	...
        {"start",                   {1,     1,    do_start}},

do_start:

static int do_start(const std::vector<std::string>& args) {
    Service* svc = ServiceManager::GetInstance().FindServiceByName(args[1]);
    if (!svc) {
        LOG(ERROR) << "do_start: Service " << args[1] << " not found";
        return -1;
    }    
    if (!svc->Start())
        return -1;
    return 0;
}

服务启动入口：

bool Service::Start() {
    // Starting a service removes it from the disabled or reset state and
    // immediately takes it out of the restarting state if it was in there.
    flags_ &= (~(SVC_DISABLED|SVC_RESTARTING|SVC_RESET|SVC_RESTART|SVC_DISABLED_START));

    // Running processes require no additional work --- if they're in the
    // process of exiting, we've ensured that they will immediately restart
    // on exit, unless they are ONESHOT.
    if (flags_ & SVC_RUNNING) {
        return false;
    } 
    ...
    LOG(INFO) << "starting service '" << name_ << "'...";

这个service就是ueventd了，入口是ueventd_main:

int ueventd_main(int argc, char** argv) {
    /*  
     * init sets the umask to 077 for forked processes. We need to
     * create files with exact permissions, without modification by
     * the umask.
     */
    umask(000);

    InitKernelLogging(argv);

    LOG(INFO) << "ueventd started!";

ok，接下来就会从queue里取出coldboot_done_action:

static int wait_for_coldboot_done_action(const std::vector<std::string>& args) {
    Timer t;

    LOG(ERROR) << "Waiting for " COLDBOOT_DONE "...";

    // Historically we had a 1s timeout here because we weren't otherwise
    // tracking boot time, and many OEMs made their sepolicy regular
    // expressions too expensive (http://b/19899875).

    // Now we're tracking boot time, just log the time taken to a system
    // property. We still panic if it takes more than a minute though,
    // because any build that slow isn't likely to boot at all, and we'd
    // rather any test lab devices fail back to the bootloader.
    if (wait_for_file(COLDBOOT_DONE, 60s) < 0) { 
        LOG(ERROR) << "Timed out waiting for " COLDBOOT_DONE;
        panic();
    }    

    property_set("ro.boottime.init.cold_boot_wait", std::to_string(t.duration().count()));
    return 0;
}

他会等待COLDBOOT_DONE文件生成，看log就是下面这个文件了：

[    2.180281] init: Waiting for /dev/.coldboot_done...

也就是等待ueventd ColdBoot跑完：

void ColdBoot::Run() {
    ...
    LOG(INFO) << "Coldboot took " << cold_boot_timer.duration().count() / 1000.0f << " seconds";
}

最后发现竟然是DoRestoreCon()耗时，看来是我们自家的sepolicy file_context太多了?

ps: 编译boot.img烧录验证。

标签：00,01,20,init,ueventd,耗时,Coldboot,action
From： https://www.cnblogs.com/linhaostudy/p/18383510

相关文章

  • 直播系统开发，接口异步调用一小步，耗时减少一大步
    直播系统开发，接口异步调用一小步，耗时减少一大步随着直播系统开发业务发展，底层数据量越来越大，业务逻辑也日趋复杂化，某些接口耗时也越来越长，这时候接口就需要进行性能优化了，当然性能优化主要跟业务相关涉及改造点可能各不相同，这里就来介绍异步调用多个接口减少响应时间。适用......
  • 耗时一天，逆天数字华容道代码
    \(O(n^3)\)处理\(n\timesn\)数字华容道还原（可能无解）。具体实现看代码：solve.cpp#include<bits/stdc++.h>usingnamespacestd;#definefifirst#definesesecondconstintN=201;intn,l,r,L,R;booltype;vector<vector<int>>a,res;vector<p......
  • 一次Kubernetes Pod内存异常导致的测试环境耗时异常问题排查过程
    概述在使用公司内部后台系统测试环境时发现一个请求加载慢的问题，简简单单的列表，查询MongoDB数据库，测试环境不过几百上千条数据而已，请求耗时居然高达5~6秒：作为对比，生产环境的请求响应截图如下：经过持续跟进，该后台系统所有列表页面测试环境普遍比生产环境慢，不管是MongoDB还是MyS......
  • 计算函数耗时
     C++计算函数耗时的类。在需要计算耗时的类里面，定义这个类的对象即可。#ifndef__ELAPSE_MILLSEC_H__#define__ELAPSE_MILLSEC_H__//#include<iostream>#include<chrono>#include<iomanip>//用于设置输出流的格式usingnamespacestd;//计算耗时class......
  • 定义一个C++的类，析构的时候输出当前函数执行耗时
    背景介绍：有时候我们需要知道一个函数的执行耗时。按照传统方法，至少要定义一个start,end,然后计算差值，输出差值，4个步骤。这里，我们定义一个  ElapseMillsec类，然后在类的生命周期结束的时候，在析构函数里面计算出差值。此时  ElapseMillsec类的生命周期，就是函数执行耗......
  • Cool Request重大更新：可以统计任意方法耗时【送源码】
    什么是CoolRequestCoolRequest是一个IDEA中的接口调试插件，除了可以发起基本的HTTP请求之外，还提供了强大的反射调用能力，可以绕过拦截器，这点广受网友的好评，当然伴随着还有Spring中对@Scheduled注解的调用，以及xxl-job的支持,这是不是很酷（Cool）?什么是Trace我怀着一颗激动的心......
  • 一个正式项目使用GraalVM进行native compile的启动耗时比较
    环境windows、graalvm(内置有JDK，可以不用再单独下载jdk了)项目pom.xml...<parent><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-parent</artifactId><version>3.2.5</version>......
  • C# 开发技巧 轻松监控方法执行耗时
    前言MethodTimer.Fody是一个功能强大的库，可以用于测量.NET应用程序中的方法的执行时间。允许你在不修改代码的情况下，自动地测量和记录方法的执行时间。这个工具是基于.NET的weaving技术，通过修改IL（IntermediateLanguage，中间语言）代码来插入计时逻辑，从而在方法调用前后记录时......
  • 一种网卡通讯慢或ping耗时较久的解决办法
    一、现象与问题        测试多台设备时候，在一个局域网的情况下，分别ping两台设备，发现ping指令耗时差距非常大，通过对比发现是其中较慢的一台设备网卡开启了PowerManagement功能，即PowerManagement:on.资料显示PowerManagement:on有以下功能 二、怀疑与疑问 ......
  • 第三节：面向切面解决问题、本地消息表实现最终一致性、热门接口耗时长问题
    一.        二.        三.         !作       者:Yaopengfei(姚鹏飞)博客地址:http://www.cnblogs.com/yaopengfei/声     明1:如有错误，欢迎讨论，请勿谩骂^_^。声     明2:原创博客请在转载......

赞助商

阅读排行

网站主页关于我们联系我们网站地图

本网站内容转载自其他媒体，侵权联系[admin##ips99.com]。

Copyright © 2020-2023 IPS99 版权所有 IPS99