Further refactoring of the bootchart code.

Change-Id: Ifed6ae8d481b605139fd27799574de4c2d0f5908
This commit is contained in:
Elliott Hughes 2015-02-12 14:28:54 -08:00
parent 265df6f50c
commit 841b263fae
5 changed files with 188 additions and 369 deletions

View file

@ -1,46 +0,0 @@
This version of init contains code to perform "bootcharting", i.e. generating log
files that can be later processed by the tools provided by www.bootchart.org.
On the emulator, use the new -bootchart <timeout> option to boot with bootcharting
activated for <timeout> seconds.
Otherwise, flash your device, and start it. Then create a file on the /data partition
with a command like the following:
adb shell 'echo $TIMEOUT > /data/bootchart/start'
Where the value of $TIMEOUT corresponds to the wanted bootcharted period in seconds;
for example, to bootchart for 2 minutes, do:
adb shell 'echo 120 > /data/bootchart/start'
Reboot your device, bootcharting will begin and stop after the period you gave.
You can also stop the bootcharting at any moment by doing the following:
adb shell 'echo 1 > /data/bootchart/stop'
Note that /data/bootchart/stop is deleted automatically by init at the end of the
bootcharting. This is not the case of /data/bootchart/start, so don't forget to delete it
when you're done collecting data:
adb shell rm /data/bootchart/start
The log files are placed in /data/bootchart/. You must run the script tools/grab-bootchart.sh
which will use ADB to retrieve them and create a bootchart.tgz file that can be used with
the bootchart parser/renderer, or even uploaded directly to the form located at:
http://www.bootchart.org/download.html
NOTE: the bootchart.org webform doesn't seem to work at the moment, you can generate an
image on your machine by doing the following:
1/ download the sources from www.bootchart.org
2/ unpack them
3/ in the source directory, type 'ant' to build the bootchart program
4/ type 'java -jar bootchart.jar /path/to/bootchart.tgz
technical note:
This implementation of bootcharting does not use the 'bootchartd' script provided by
www.bootchart.org, but a C re-implementation that is directly compiled into our init
program.

View file

@ -14,15 +14,10 @@
* limitations under the License. * limitations under the License.
*/ */
/* this code is used to generate a boot sequence profile that can be used
* with the 'bootchart' graphics generation tool. see www.bootchart.org
* note that unlike the original bootchartd, this is not a Bash script but
* some C code that is run right from the init script.
*/
#include "bootchart.h" #include "bootchart.h"
#include "keywords.h" #include "keywords.h"
#include "log.h" #include "log.h"
#include "property_service.h"
#include <dirent.h> #include <dirent.h>
#include <errno.h> #include <errno.h>
@ -31,15 +26,14 @@
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
#include <sys/stat.h> #include <sys/stat.h>
#include <sys/utsname.h>
#include <time.h> #include <time.h>
#include <unistd.h> #include <unistd.h>
#define BOOTCHART_POLLING_MS 200 /* polling period in ms */ #include <string>
#define BOOTCHART_DEFAULT_TIME_SEC (2*60) /* default polling time in seconds */
#define BOOTCHART_MAX_TIME_SEC (10*60) /* max polling time in seconds */ #include <utils/file.h>
#define VERSION "0.8"
#define SAMPLE_PERIOD 0.2
#define LOG_ROOT "/data/bootchart" #define LOG_ROOT "/data/bootchart"
#define LOG_STAT LOG_ROOT"/proc_stat.log" #define LOG_STAT LOG_ROOT"/proc_stat.log"
#define LOG_PROCS LOG_ROOT"/proc_ps.log" #define LOG_PROCS LOG_ROOT"/proc_ps.log"
@ -50,257 +44,133 @@
#define LOG_STARTFILE LOG_ROOT"/start" #define LOG_STARTFILE LOG_ROOT"/start"
#define LOG_STOPFILE LOG_ROOT"/stop" #define LOG_STOPFILE LOG_ROOT"/stop"
#define FILE_BUFF_SIZE 65536 // Polling period in ms.
static const int BOOTCHART_POLLING_MS = 200;
struct FileBuff { // Default polling time in seconds.
int count; static const int BOOTCHART_DEFAULT_TIME_SEC = 2*60;
int fd;
char data[FILE_BUFF_SIZE];
};
static long long last_bootchart_time; // Max polling time in seconds.
static const int BOOTCHART_MAX_TIME_SEC = 10*60;
static long long g_last_bootchart_time;
static int g_remaining_samples; static int g_remaining_samples;
static FileBuff log_stat[1]; static FILE* log_stat;
static FileBuff log_procs[1]; static FILE* log_procs;
static FileBuff log_disks[1]; static FILE* log_disks;
static int static long long get_uptime_jiffies() {
proc_read(const char* filename, char* buff, size_t buffsize) std::string uptime;
{ if (!android::ReadFileToString("/proc/uptime", &uptime)) {
int len = 0; return 0;
int fd = open(filename, O_RDONLY | O_CLOEXEC);
if (fd >= 0) {
len = TEMP_FAILURE_RETRY(read(fd, buff, buffsize-1));
close(fd);
} }
buff[len > 0 ? len : 0] = 0; return 100LL * strtod(uptime.c_str(), NULL);
return len;
} }
static void static void log_header() {
file_buff_open( FileBuff* buff, const char* path ) char date[32];
{ time_t now_t = time(NULL);
buff->count = 0; struct tm now = *localtime(&now_t);
buff->fd = open(path, O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC, 0755); strftime(date, sizeof(date), "%F %T", &now);
}
static void utsname uts;
file_buff_write( FileBuff* buff, const void* src, int len ) if (uname(&uts) == -1) {
{
while (len > 0) {
int avail = sizeof(buff->data) - buff->count;
if (avail > len)
avail = len;
memcpy( buff->data + buff->count, src, avail );
len -= avail;
src = (char*)src + avail;
buff->count += avail;
if (buff->count == FILE_BUFF_SIZE) {
TEMP_FAILURE_RETRY(write(buff->fd, buff->data, buff->count));
buff->count = 0;
}
}
}
static void
file_buff_done( FileBuff* buff )
{
if (buff->count > 0) {
TEMP_FAILURE_RETRY(write(buff->fd, buff->data, buff->count));
buff->count = 0;
}
}
static long long
get_uptime_jiffies()
{
char buff[64];
long long jiffies = 0;
if (proc_read("/proc/uptime", buff, sizeof(buff)) > 0)
jiffies = 100LL*strtod(buff,NULL);
return jiffies;
}
static void
log_header(void)
{
FILE* out;
char cmdline[1024];
char uname[128];
char cpuinfo[128];
char* cpu;
char date[32];
time_t now_t = time(NULL);
struct tm now = *localtime(&now_t);
strftime(date, sizeof(date), "%x %X", &now);
out = fopen( LOG_HEADER, "we" );
if (out == NULL)
return; return;
proc_read("/proc/cmdline", cmdline, sizeof(cmdline));
proc_read("/proc/version", uname, sizeof(uname));
proc_read("/proc/cpuinfo", cpuinfo, sizeof(cpuinfo));
cpu = strchr( cpuinfo, ':' );
if (cpu) {
char* p = strchr(cpu, '\n');
cpu += 2;
if (p)
*p = 0;
} }
fprintf(out, "version = %s\n", VERSION); char fingerprint[PROP_VALUE_MAX];
fprintf(out, "title = Boot chart for Android ( %s )\n", date); if (property_get("ro.build.fingerprint", fingerprint) == -1) {
fprintf(out, "system.uname = %s\n", uname); return;
fprintf(out, "system.release = 0.0\n"); }
fprintf(out, "system.cpu = %s\n", cpu);
fprintf(out, "system.kernel.options = %s\n", cmdline); std::string kernel_cmdline;
android::ReadFileToString("/proc/cmdline", &kernel_cmdline);
FILE* out = fopen(LOG_HEADER, "we");
if (out == NULL) {
return;
}
fprintf(out, "version = Android init 0.8 " __TIME__ "\n");
fprintf(out, "title = Boot chart for Android (%s)\n", date);
fprintf(out, "system.uname = %s %s %s %s\n", uts.sysname, uts.release, uts.version, uts.machine);
fprintf(out, "system.release = %s\n", fingerprint);
// TODO: use /proc/cpuinfo "model name" line for x86, "Processor" line for arm.
fprintf(out, "system.cpu = %s\n", uts.machine);
fprintf(out, "system.kernel.options = %s\n", kernel_cmdline.c_str());
fclose(out); fclose(out);
} }
static void static void do_log_uptime(FILE* log) {
do_log_uptime(FileBuff* log) fprintf(log, "%lld\n", get_uptime_jiffies());
{
char buff[65];
int len;
snprintf(buff,sizeof(buff),"%lld\n",get_uptime_jiffies());
len = strlen(buff);
file_buff_write(log, buff, len);
} }
static void static void do_log_file(FILE* log, const char* procfile) {
do_log_ln(FileBuff* log)
{
file_buff_write(log, "\n", 1);
}
static void
do_log_file(FileBuff* log, const char* procfile)
{
char buff[1024];
int fd;
do_log_uptime(log); do_log_uptime(log);
/* append file content */ std::string content;
fd = open(procfile,O_RDONLY|O_CLOEXEC); if (android::ReadFileToString(procfile, &content)) {
if (fd >= 0) { fprintf(log, "%s\n", content.c_str());
for (;;) {
int ret = TEMP_FAILURE_RETRY(read(fd, buff, sizeof(buff)));
if (ret <= 0)
break;
file_buff_write(log, buff, ret);
if (ret < (int)sizeof(buff))
break;
}
close(fd);
} }
do_log_ln(log);
} }
static void static void do_log_procs(FILE* log) {
do_log_procs(FileBuff* log)
{
DIR* dir = opendir("/proc");
struct dirent* entry;
do_log_uptime(log); do_log_uptime(log);
DIR* dir = opendir("/proc");
struct dirent* entry;
while ((entry = readdir(dir)) != NULL) { while ((entry = readdir(dir)) != NULL) {
/* only match numeric values */ // Only match numeric values.
char* end; char* end;
int pid = strtol( entry->d_name, &end, 10); int pid = strtol(entry->d_name, &end, 10);
if (end != NULL && end > entry->d_name && *end == 0) { if (end != NULL && end > entry->d_name && *end == 0) {
char filename[32]; char filename[32];
char buff[1024];
char cmdline[1024];
int len;
int fd;
/* read command line and extract program name */ // /proc/<pid>/stat only has truncated task names, so get the full
snprintf(filename,sizeof(filename),"/proc/%d/cmdline",pid); // name from /proc/<pid>/cmdline.
proc_read(filename, cmdline, sizeof(cmdline)); snprintf(filename, sizeof(filename), "/proc/%d/cmdline", pid);
std::string cmdline;
android::ReadFileToString(filename, &cmdline);
const char* full_name = cmdline.c_str(); // So we stop at the first NUL.
/* read process stat line */ // Read process stat line.
snprintf(filename,sizeof(filename),"/proc/%d/stat",pid); snprintf(filename, sizeof(filename), "/proc/%d/stat", pid);
fd = open(filename,O_RDONLY|O_CLOEXEC); std::string stat;
if (fd >= 0) { if (android::ReadFileToString(filename, &stat)) {
len = TEMP_FAILURE_RETRY(read(fd, buff, sizeof(buff)-1)); if (!cmdline.empty()) {
close(fd); // Substitute the process name with its real name.
if (len > 0) { size_t open = stat.find('(');
int len2 = strlen(cmdline); size_t close = stat.find_last_of(')');
if (len2 > 0) { if (open != std::string::npos && close != std::string::npos) {
/* we want to substitute the process name with its real name */ stat.replace(open + 1, close - open - 1, full_name);
const char* p1;
const char* p2;
buff[len] = 0;
p1 = strchr(buff, '(');
p2 = strchr(p1, ')');
file_buff_write(log, buff, p1+1-buff);
file_buff_write(log, cmdline, strlen(cmdline));
file_buff_write(log, p2, strlen(p2));
} else {
/* no substitution */
file_buff_write(log,buff,len);
} }
} }
fputs(stat.c_str(), log);
} }
} }
} }
closedir(dir); closedir(dir);
do_log_ln(log);
fputc('\n', log);
} }
int do_bootchart_init(int nargs, char **args) static int bootchart_init() {
{ int timeout = 0;
g_remaining_samples = bootchart_init();
if (g_remaining_samples < 0) { std::string start;
ERROR("bootcharting init failure\n"); android::ReadFileToString(LOG_STARTFILE, &start);
} else if (g_remaining_samples > 0) { if (!start.empty()) {
NOTICE("bootcharting started (will run for %d ms)\n", g_remaining_samples*BOOTCHART_POLLING_MS); timeout = atoi(start.c_str());
} else { } else {
NOTICE("bootcharting ignored\n"); // When running with emulator, androidboot.bootchart=<timeout>
} // might be passed by as kernel parameters to specify the bootchart
// timeout. this is useful when using -wipe-data since the /data
return 0; // partition is fresh.
} std::string cmdline;
android::ReadFileToString("/proc/cmdline", &cmdline);
/* called to setup bootcharting */ #define KERNEL_OPTION "androidboot.bootchart="
int bootchart_init( void ) if (strstr(cmdline.c_str(), KERNEL_OPTION) != NULL) {
{ timeout = atoi(cmdline.c_str() + sizeof(KERNEL_OPTION) - 1);
int ret;
char buff[4];
int timeout = 0, count = 0;
buff[0] = 0;
proc_read( LOG_STARTFILE, buff, sizeof(buff) );
if (buff[0] != 0) {
timeout = atoi(buff);
}
else {
/* when running with emulator, androidboot.bootchart=<timeout>
* might be passed by as kernel parameters to specify the bootchart
* timeout. this is useful when using -wipe-data since the /data
* partition is fresh
*/
char cmdline[1024];
char* s;
#define KERNEL_OPTION "androidboot.bootchart="
proc_read( "/proc/cmdline", cmdline, sizeof(cmdline) );
s = strstr(cmdline, KERNEL_OPTION);
if (s) {
s += sizeof(KERNEL_OPTION)-1;
timeout = atoi(s);
} }
} }
if (timeout == 0) if (timeout == 0)
@ -309,15 +179,25 @@ int bootchart_init( void )
if (timeout > BOOTCHART_MAX_TIME_SEC) if (timeout > BOOTCHART_MAX_TIME_SEC)
timeout = BOOTCHART_MAX_TIME_SEC; timeout = BOOTCHART_MAX_TIME_SEC;
count = (timeout*1000 + BOOTCHART_POLLING_MS-1)/BOOTCHART_POLLING_MS; int count = (timeout*1000 + BOOTCHART_POLLING_MS-1)/BOOTCHART_POLLING_MS;
ret = TEMP_FAILURE_RETRY(mkdir(LOG_ROOT,0755)); log_stat = fopen(LOG_STAT, "we");
if (log_stat == NULL) {
return -1;
}
log_procs = fopen(LOG_PROCS, "we");
if (log_procs == NULL) {
fclose(log_stat);
return -1;
}
log_disks = fopen(LOG_DISK, "we");
if (log_disks == NULL) {
fclose(log_stat);
fclose(log_procs);
return -1;
}
file_buff_open(log_stat, LOG_STAT); // Create kernel process accounting file.
file_buff_open(log_procs, LOG_PROCS);
file_buff_open(log_disks, LOG_DISK);
/* create kernel process accounting file */
{ {
int fd = open( LOG_ACCT, O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC,0644); int fd = open( LOG_ACCT, O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC,0644);
if (fd >= 0) { if (fd >= 0) {
@ -330,18 +210,27 @@ int bootchart_init( void )
return count; return count;
} }
static int bootchart_step( void ) int do_bootchart_init(int nargs, char** args) {
{ g_remaining_samples = bootchart_init();
if (g_remaining_samples < 0) {
ERROR("bootcharting init failure: %s\n", strerror(errno));
} else if (g_remaining_samples > 0) {
NOTICE("bootcharting started (will run for %d ms)\n", g_remaining_samples*BOOTCHART_POLLING_MS);
} else {
NOTICE("bootcharting ignored\n");
}
return 0;
}
static int bootchart_step() {
do_log_file(log_stat, "/proc/stat"); do_log_file(log_stat, "/proc/stat");
do_log_file(log_disks, "/proc/diskstats"); do_log_file(log_disks, "/proc/diskstats");
do_log_procs(log_procs); do_log_procs(log_procs);
/* we stop when /data/bootchart/stop contains 1 */ // Stop if /data/bootchart/stop contains 1.
{ std::string stop;
char buff[2]; if (android::ReadFileToString(LOG_STOPFILE, &stop) && stop == "1") {
if (proc_read(LOG_STOPFILE,buff,sizeof(buff)) > 0 && buff[0] == '1') { return -1;
return -1;
}
} }
return 0; return 0;
@ -352,42 +241,40 @@ static long long bootchart_gettime() {
return 10LL*get_uptime_jiffies(); return 10LL*get_uptime_jiffies();
} }
/* called each time you want to perform a bootchart sampling op */ static void bootchart_finish() {
unlink(LOG_STOPFILE);
fclose(log_stat);
fclose(log_disks);
fclose(log_procs);
acct(NULL);
}
void bootchart_sample(int* timeout) { void bootchart_sample(int* timeout) {
if (g_remaining_samples > 0) { // Do we have any more bootcharting to do?
long long current_time; if (g_remaining_samples <= 0) {
int elapsed_time, remaining_time; return;
}
current_time = bootchart_gettime(); long long current_time = bootchart_gettime();
elapsed_time = current_time - last_bootchart_time; int elapsed_time = current_time - g_last_bootchart_time;
if (elapsed_time >= BOOTCHART_POLLING_MS) { if (elapsed_time >= BOOTCHART_POLLING_MS) {
/* count missed samples */ /* count missed samples */
while (elapsed_time >= BOOTCHART_POLLING_MS) { while (elapsed_time >= BOOTCHART_POLLING_MS) {
elapsed_time -= BOOTCHART_POLLING_MS; elapsed_time -= BOOTCHART_POLLING_MS;
g_remaining_samples--; g_remaining_samples--;
}
/* count may be negative, take a sample anyway */
last_bootchart_time = current_time;
if (bootchart_step() < 0 || g_remaining_samples <= 0) {
bootchart_finish();
g_remaining_samples = 0;
}
} }
if (g_remaining_samples > 0) { /* count may be negative, take a sample anyway */
remaining_time = BOOTCHART_POLLING_MS - elapsed_time; g_last_bootchart_time = current_time;
if (*timeout < 0 || *timeout > remaining_time) { if (bootchart_step() < 0 || g_remaining_samples <= 0) {
*timeout = remaining_time; bootchart_finish();
} g_remaining_samples = 0;
}
}
if (g_remaining_samples > 0) {
int remaining_time = BOOTCHART_POLLING_MS - elapsed_time;
if (*timeout < 0 || *timeout > remaining_time) {
*timeout = remaining_time;
} }
} }
} }
void bootchart_finish( void )
{
unlink( LOG_STOPFILE );
file_buff_done(log_stat);
file_buff_done(log_disks);
file_buff_done(log_procs);
acct(NULL);
}

View file

@ -17,8 +17,6 @@
#ifndef _BOOTCHART_H #ifndef _BOOTCHART_H
#define _BOOTCHART_H #define _BOOTCHART_H
int bootchart_init();
void bootchart_sample(int* timeout); void bootchart_sample(int* timeout);
void bootchart_finish();
#endif /* _BOOTCHART_H */ #endif /* _BOOTCHART_H */

View file

@ -17,7 +17,7 @@
#ifndef _INIT_PROPERTY_H #ifndef _INIT_PROPERTY_H
#define _INIT_PROPERTY_H #define _INIT_PROPERTY_H
#include <stdbool.h> #include <stddef.h>
#include <sys/system_properties.h> #include <sys/system_properties.h>
extern void handle_property_set_fd(void); extern void handle_property_set_fd(void);

View file

@ -110,6 +110,7 @@ class <name>
onrestart onrestart
Execute a Command (see below) when service restarts. Execute a Command (see below) when service restarts.
Triggers Triggers
-------- --------
Triggers are strings which can be used to match certain kinds Triggers are strings which can be used to match certain kinds
@ -132,6 +133,7 @@ boot
The above stub sets test.c to 1 only when The above stub sets test.c to 1 only when
both test.a=1 and test.b=1 both test.a=1 and test.b=1
Commands Commands
-------- --------
@ -283,63 +285,41 @@ init.svc.<name>
State of a named service ("stopped", "running", "restarting") State of a named service ("stopped", "running", "restarting")
Example init.conf Bootcharting
----------------- ------------
# not complete -- just providing some examples of usage This version of init contains code to perform "bootcharting": generating log
# files that can be later processed by the tools provided by www.bootchart.org.
on boot
export PATH /sbin:/system/sbin:/system/bin
export LD_LIBRARY_PATH /system/lib
mkdir /dev On the emulator, use the new -bootchart <timeout> option to boot with
mkdir /proc bootcharting activated for <timeout> seconds.
mkdir /sys
mount tmpfs tmpfs /dev On a device, create /data/bootchart/start with a command like the following:
mkdir /dev/pts
mkdir /dev/socket
mount devpts devpts /dev/pts
mount proc proc /proc
mount sysfs sysfs /sys
write /proc/cpu/alignment 4 adb shell 'echo $TIMEOUT > /data/bootchart/start'
ifup lo Where the value of $TIMEOUT corresponds to the desired bootcharted period in
seconds. Bootcharting will stop after that many seconds have elapsed.
You can also stop the bootcharting at any moment by doing the following:
hostname localhost adb shell 'echo 1 > /data/bootchart/stop'
domainname localhost
mount yaffs2 mtd@system /system Note that /data/bootchart/stop is deleted automatically by init at the end of
mount yaffs2 mtd@userdata /data the bootcharting. This is not the case with /data/bootchart/start, so don't
forget to delete it when you're done collecting data.
import /system/etc/init.conf The log files are written to /data/bootchart/. A script is provided to
retrieve them and create a bootchart.tgz file that can be used with the
bootchart command-line utility:
class_start default sudo apt-get install pybootchartgui
$ANDROID_BUILD_TOP/system/core/init/grab-bootchart.sh
bootchart ./bootchart.tgz
gnome-open bootchart.png
service adbd /sbin/adbd
user adb
group adb
service usbd /system/bin/usbd -r Debugging init
user usbd --------------
group usbd
socket usbd 666
service zygote /system/bin/app_process -Xzygote /system/bin --zygote
socket zygote 666
service runtime /system/bin/runtime
user system
group system
service akmd /sbin/akmd
disabled
user akmd
group akmd
Debugging notes
---------------
By default, programs executed by init will drop stdout and stderr into By default, programs executed by init will drop stdout and stderr into
/dev/null. To help with debugging, you can execute your program via the /dev/null. To help with debugging, you can execute your program via the
Android program logwrapper. This will redirect stdout/stderr into the Android program logwrapper. This will redirect stdout/stderr into the
@ -350,7 +330,7 @@ service akmd /system/bin/logwrapper /sbin/akmd
For quicker turnaround when working on init itself, use: For quicker turnaround when working on init itself, use:
mm mm -j
m ramdisk-nodeps m ramdisk-nodeps
m bootimage-nodeps m bootimage-nodeps
adb reboot bootloader adb reboot bootloader