tools/gator/daemon/PerfSource.cpp

   1 /**
   2  * Copyright (C) ARM Limited 2010-2014. All rights reserved.
   3  *
   4  * This program is free software; you can redistribute it and/or modify
   5  * it under the terms of the GNU General Public License version 2 as
   6  * published by the Free Software Foundation.
   7  */
   8
   9 #include "PerfSource.h"
  10
  11 #include <dirent.h>
  12 #include <errno.h>
  13 #include <signal.h>
  14 #include <string.h>
  15 #include <sys/prctl.h>
  16 #include <sys/resource.h>
  17 #include <sys/syscall.h>
  18 #include <sys/types.h>
  19 #include <unistd.h>
  20
  21 #include "Child.h"
  22 #include "DynBuf.h"
  23 #include "Logging.h"
  24 #include "PerfDriver.h"
  25 #include "Proc.h"
  26 #include "SessionData.h"
  27
  28 #ifndef SCHED_RESET_ON_FORK
  29 #define SCHED_RESET_ON_FORK 0x40000000
  30 #endif
  31
  32 extern Child *child;
  33
  34 static bool sendTracepointFormat(const uint64_t currTime, Buffer *const buffer, const char *const name, DynBuf *const printb, DynBuf *const b) {
  35         if (!printb->printf(EVENTS_PATH "/%s/format", name)) {
  36                 logg->logMessage("%s(%s:%i): DynBuf::printf failed", __FUNCTION__, __FILE__, __LINE__);
  37                 return false;
  38         }
  39         if (!b->read(printb->getBuf())) {
  40                 logg->logMessage("%s(%s:%i): DynBuf::read failed", __FUNCTION__, __FILE__, __LINE__);
  41                 return false;
  42         }
  43         buffer->format(currTime, b->getLength(), b->getBuf());
  44
  45         return true;
  46 }
  47
  48 static void *syncFunc(void *arg)
  49 {
  50         struct timespec ts;
  51         int64_t nextTime = gSessionData->mMonotonicStarted;
  52         int err;
  53         (void)arg;
  54
  55         prctl(PR_SET_NAME, (unsigned long)&"gatord-sync", 0, 0, 0);
  56
  57         // Mask all signals so that this thread will not be woken up
  58         {
  59                 sigset_t set;
  60                 if (sigfillset(&set) != 0) {
  61                         logg->logError(__FILE__, __LINE__, "sigfillset failed");
  62                         handleException();
  63                 }
  64                 if ((err = pthread_sigmask(SIG_SETMASK, &set, NULL)) != 0) {
  65                         logg->logError(__FILE__, __LINE__, "pthread_sigmask failed");
  66                         handleException();
  67                 }
  68         }
  69
  70         for (;;) {
  71                 if (clock_gettime(CLOCK_MONOTONIC_RAW, &ts) != 0) {
  72                         logg->logError(__FILE__, __LINE__, "clock_gettime failed");
  73                         handleException();
  74                 }
  75                 const int64_t currTime = ts.tv_sec * NS_PER_S + ts.tv_nsec;
  76
  77                 // Wake up once a second
  78                 nextTime += NS_PER_S;
  79
  80                 // Always sleep more than 1 ms, hopefully things will line up better next time
  81                 const int64_t sleepTime = max(nextTime - currTime, (int64_t)(NS_PER_MS + 1));
  82                 ts.tv_sec = sleepTime/NS_PER_S;
  83                 ts.tv_nsec = sleepTime % NS_PER_S;
  84
  85                 err = nanosleep(&ts, NULL);
  86                 if (err != 0) {
  87                         fprintf(stderr, "clock_nanosleep failed: %s\n", strerror(err));
  88                         return NULL;
  89                 }
  90         }
  91
  92         return NULL;
  93 }
  94
  95 static long getMaxCoreNum() {
  96         DIR *dir = opendir("/sys/devices/system/cpu");
  97         if (dir == NULL) {
  98                 logg->logError(__FILE__, __LINE__, "Unable to determine the number of cores on the target, opendir failed");
  99                 handleException();
 100         }
 101
 102         long maxCoreNum = -1;
 103         struct dirent *dirent;
 104         while ((dirent = readdir(dir)) != NULL) {
 105                 if (strncmp(dirent->d_name, "cpu", 3) == 0) {
 106                         char *endptr;
 107                         errno = 0;
 108                         long coreNum = strtol(dirent->d_name + 3, &endptr, 10);
 109                         if ((errno == 0) && (*endptr == '\0') && (coreNum >= maxCoreNum)) {
 110                                 maxCoreNum = coreNum + 1;
 111                         }
 112                 }
 113         }
 114         closedir(dir);
 115
 116         if (maxCoreNum < 1) {
 117                 logg->logError(__FILE__, __LINE__, "Unable to determine the number of cores on the target, no cpu# directories found");
 118                 handleException();
 119         }
 120
 121         if (maxCoreNum >= NR_CPUS) {
 122                 logg->logError(__FILE__, __LINE__, "Too many cores on the target, please increase NR_CPUS in Config.h");
 123                 handleException();
 124         }
 125
 126         return maxCoreNum;
 127 }
 128
 129 PerfSource::PerfSource(sem_t *senderSem, sem_t *startProfile) : mSummary(0, FRAME_SUMMARY, 1024, senderSem), mBuffer(0, FRAME_PERF_ATTRS, 1024*1024, senderSem), mCountersBuf(), mCountersGroup(&mCountersBuf), mIdleGroup(&mCountersBuf), mMonitor(), mUEvent(), mSenderSem(senderSem), mStartProfile(startProfile), mInterruptFd(-1), mIsDone(false) {
 130         long l = sysconf(_SC_PAGE_SIZE);
 131         if (l < 0) {
 132                 logg->logError(__FILE__, __LINE__, "Unable to obtain the page size");
 133                 handleException();
 134         }
 135         gSessionData->mPageSize = static_cast<int>(l);
 136         gSessionData->mCores = static_cast<int>(getMaxCoreNum());
 137 }
 138
 139 PerfSource::~PerfSource() {
 140 }
 141
 142 bool PerfSource::prepare() {
 143         DynBuf printb;
 144         DynBuf b1;
 145         long long schedSwitchId;
 146         long long cpuIdleId;
 147
 148         const uint64_t currTime = getTime();
 149
 150         // Reread cpuinfo since cores may have changed since startup
 151         gSessionData->readCpuInfo();
 152
 153         if (0
 154                         || !mMonitor.init()
 155                         || !mUEvent.init()
 156                         || !mMonitor.add(mUEvent.getFd())
 157
 158                         || (schedSwitchId = PerfDriver::getTracepointId(SCHED_SWITCH, &printb)) < 0
 159                         || !sendTracepointFormat(currTime, &mBuffer, SCHED_SWITCH, &printb, &b1)
 160
 161                         || (cpuIdleId = PerfDriver::getTracepointId(CPU_IDLE, &printb)) < 0
 162                         || !sendTracepointFormat(currTime, &mBuffer, CPU_IDLE, &printb, &b1)
 163
 164                         // Only want RAW but not IP on sched_switch and don't want TID on SAMPLE_ID
 165                         || !mCountersGroup.add(currTime, &mBuffer, 100/**/, PERF_TYPE_TRACEPOINT, schedSwitchId, 1, PERF_SAMPLE_RAW, PERF_GROUP_MMAP | PERF_GROUP_COMM | PERF_GROUP_TASK | PERF_GROUP_SAMPLE_ID_ALL | PERF_GROUP_PER_CPU)
 166                         || !mIdleGroup.add(currTime, &mBuffer, 101/**/, PERF_TYPE_TRACEPOINT, cpuIdleId, 1, PERF_SAMPLE_RAW, PERF_GROUP_PER_CPU)
 167
 168                         // Only want TID and IP but not RAW on timer
 169                         || (gSessionData->mSampleRate > 0 && !gSessionData->mIsEBS && !mCountersGroup.add(currTime, &mBuffer, 102/**/, PERF_TYPE_SOFTWARE, PERF_COUNT_SW_CPU_CLOCK, 1000000000UL / gSessionData->mSampleRate, PERF_SAMPLE_TID | PERF_SAMPLE_IP, PERF_GROUP_PER_CPU))
 170
 171                         || !gSessionData->perf.enable(currTime, &mCountersGroup, &mBuffer)
 172                         || 0) {
 173                 logg->logMessage("%s(%s:%i): perf setup failed, are you running Linux 3.4 or later?", __FUNCTION__, __FILE__, __LINE__);
 174                 return false;
 175         }
 176
 177         for (int cpu = 0; cpu < gSessionData->mCores; ++cpu) {
 178                 const int result = mCountersGroup.prepareCPU(cpu, &mMonitor);
 179                 if ((result != PG_SUCCESS) && (result != PG_CPU_OFFLINE)) {
 180                         logg->logError(__FILE__, __LINE__, "PerfGroup::prepareCPU on mCountersGroup failed");
 181                         handleException();
 182                 }
 183         }
 184         for (int cpu = 0; cpu < gSessionData->mCores; ++cpu) {
 185                 const int result = mIdleGroup.prepareCPU(cpu, &mMonitor);
 186                 if ((result != PG_SUCCESS) && (result != PG_CPU_OFFLINE)) {
 187                         logg->logError(__FILE__, __LINE__, "PerfGroup::prepareCPU on mIdleGroup failed");
 188                         handleException();
 189                 }
 190         }
 191
 192         int numEvents = 0;
 193         for (int cpu = 0; cpu < gSessionData->mCores; ++cpu) {
 194                 numEvents += mCountersGroup.onlineCPU(currTime, cpu, false, &mBuffer);
 195         }
 196         for (int cpu = 0; cpu < gSessionData->mCores; ++cpu) {
 197                 numEvents += mIdleGroup.onlineCPU(currTime, cpu, false, &mBuffer);
 198         }
 199         if (numEvents <= 0) {
 200                 logg->logMessage("%s(%s:%i): PerfGroup::onlineCPU failed on all cores", __FUNCTION__, __FILE__, __LINE__);
 201                 return false;
 202         }
 203
 204         // Send the summary right before the start so that the monotonic delta is close to the start time
 205         if (!gSessionData->perf.summary(&mSummary)) {
 206           logg->logError(__FILE__, __LINE__, "PerfDriver::summary failed", __FUNCTION__, __FILE__, __LINE__);
 207           handleException();
 208         }
 209
 210         // Start the timer thread to used to sync perf and monotonic raw times
 211         pthread_t syncThread;
 212         if (pthread_create(&syncThread, NULL, syncFunc, NULL)) {
 213           logg->logError(__FILE__, __LINE__, "pthread_create failed", __FUNCTION__, __FILE__, __LINE__);
 214           handleException();
 215         }
 216         struct sched_param param;
 217         param.sched_priority = sched_get_priority_max(SCHED_FIFO);
 218         if (pthread_setschedparam(syncThread, SCHED_FIFO | SCHED_RESET_ON_FORK, &param) != 0) {
 219           logg->logError(__FILE__, __LINE__, "pthread_setschedparam failed");
 220           handleException();
 221         }
 222
 223         mBuffer.commit(currTime);
 224
 225         return true;
 226 }
 227
 228 struct ProcThreadArgs {
 229         Buffer *mBuffer;
 230         uint64_t mCurrTime;
 231         bool mIsDone;
 232 };
 233
 234 void *procFunc(void *arg) {
 235         DynBuf printb;
 236         DynBuf b;
 237         const ProcThreadArgs *const args = (ProcThreadArgs *)arg;
 238
 239         prctl(PR_SET_NAME, (unsigned long)&"gatord-proc", 0, 0, 0);
 240
 241         // Gator runs at a high priority, reset the priority to the default
 242         if (setpriority(PRIO_PROCESS, syscall(__NR_gettid), 0) == -1) {
 243                 logg->logError(__FILE__, __LINE__, "setpriority failed");
 244                 handleException();
 245         }
 246
 247         if (!readProcMaps(args->mCurrTime, args->mBuffer, &printb, &b)) {
 248                 logg->logError(__FILE__, __LINE__, "readProcMaps failed");
 249                 handleException();
 250         }
 251         args->mBuffer->commit(args->mCurrTime);
 252
 253         if (!readKallsyms(args->mCurrTime, args->mBuffer, &args->mIsDone)) {
 254                 logg->logError(__FILE__, __LINE__, "readKallsyms failed");
 255                 handleException();
 256         }
 257         args->mBuffer->commit(args->mCurrTime);
 258
 259         return NULL;
 260 }
 261
 262 static const char CPU_DEVPATH[] = "/devices/system/cpu/cpu";
 263
 264 void PerfSource::run() {
 265         int pipefd[2];
 266         pthread_t procThread;
 267         ProcThreadArgs procThreadArgs;
 268
 269         {
 270                 DynBuf printb;
 271                 DynBuf b1;
 272                 DynBuf b2;
 273
 274                 const uint64_t currTime = getTime();
 275
 276                 // Start events before reading proc to avoid race conditions
 277                 if (!mCountersGroup.start() || !mIdleGroup.start()) {
 278                         logg->logError(__FILE__, __LINE__, "PerfGroup::start failed", __FUNCTION__, __FILE__, __LINE__);
 279                         handleException();
 280                 }
 281
 282                 if (!readProcComms(currTime, &mBuffer, &printb, &b1, &b2)) {
 283                         logg->logError(__FILE__, __LINE__, "readProcComms failed");
 284                         handleException();
 285                 }
 286                 mBuffer.commit(currTime);
 287
 288                 // Postpone reading kallsyms as on android adb gets too backed up and data is lost
 289                 procThreadArgs.mBuffer = &mBuffer;
 290                 procThreadArgs.mCurrTime = currTime;
 291                 procThreadArgs.mIsDone = false;
 292                 if (pthread_create(&procThread, NULL, procFunc, &procThreadArgs)) {
 293                         logg->logError(__FILE__, __LINE__, "pthread_create failed", __FUNCTION__, __FILE__, __LINE__);
 294                         handleException();
 295                 }
 296         }
 297
 298         if (pipe_cloexec(pipefd) != 0) {
 299                 logg->logError(__FILE__, __LINE__, "pipe failed");
 300                 handleException();
 301         }
 302         mInterruptFd = pipefd[1];
 303
 304         if (!mMonitor.add(pipefd[0])) {
 305                 logg->logError(__FILE__, __LINE__, "Monitor::add failed");
 306                 handleException();
 307         }
 308
 309         int timeout = -1;
 310         if (gSessionData->mLiveRate > 0) {
 311                 timeout = gSessionData->mLiveRate/NS_PER_MS;
 312         }
 313
 314         sem_post(mStartProfile);
 315
 316         while (gSessionData->mSessionIsActive) {
 317                 // +1 for uevents, +1 for pipe
 318                 struct epoll_event events[NR_CPUS + 2];
 319                 int ready = mMonitor.wait(events, ARRAY_LENGTH(events), timeout);
 320                 if (ready < 0) {
 321                         logg->logError(__FILE__, __LINE__, "Monitor::wait failed");
 322                         handleException();
 323                 }
 324                 const uint64_t currTime = getTime();
 325
 326                 for (int i = 0; i < ready; ++i) {
 327                         if (events[i].data.fd == mUEvent.getFd()) {
 328                                 if (!handleUEvent(currTime)) {
 329                                         logg->logError(__FILE__, __LINE__, "PerfSource::handleUEvent failed");
 330                                         handleException();
 331                                 }
 332                                 break;
 333                         }
 334                 }
 335
 336                 // send a notification that data is ready
 337                 sem_post(mSenderSem);
 338
 339                 // In one shot mode, stop collection once all the buffers are filled
 340                 // Assume timeout == 0 in this case
 341                 if (gSessionData->mOneShot && gSessionData->mSessionIsActive) {
 342                         logg->logMessage("%s(%s:%i): One shot", __FUNCTION__, __FILE__, __LINE__);
 343                         child->endSession();
 344                 }
 345         }
 346
 347         procThreadArgs.mIsDone = true;
 348         pthread_join(procThread, NULL);
 349         mIdleGroup.stop();
 350         mCountersGroup.stop();
 351         mBuffer.setDone();
 352         mIsDone = true;
 353
 354         // send a notification that data is ready
 355         sem_post(mSenderSem);
 356
 357         mInterruptFd = -1;
 358         close(pipefd[0]);
 359         close(pipefd[1]);
 360 }
 361
 362 bool PerfSource::handleUEvent(const uint64_t currTime) {
 363         UEventResult result;
 364         if (!mUEvent.read(&result)) {
 365                 logg->logMessage("%s(%s:%i): UEvent::Read failed", __FUNCTION__, __FILE__, __LINE__);
 366                 return false;
 367         }
 368
 369         if (strcmp(result.mSubsystem, "cpu") == 0) {
 370                 if (strncmp(result.mDevPath, CPU_DEVPATH, sizeof(CPU_DEVPATH) - 1) != 0) {
 371                         logg->logMessage("%s(%s:%i): Unexpected cpu DEVPATH format", __FUNCTION__, __FILE__, __LINE__);
 372                         return false;
 373                 }
 374                 char *endptr;
 375                 errno = 0;
 376                 int cpu = strtol(result.mDevPath + sizeof(CPU_DEVPATH) - 1, &endptr, 10);
 377                 if (errno != 0 || *endptr != '\0') {
 378                         logg->logMessage("%s(%s:%i): strtol failed", __FUNCTION__, __FILE__, __LINE__);
 379                         return false;
 380                 }
 381
 382                 if (cpu >= gSessionData->mCores) {
 383                         logg->logError(__FILE__, __LINE__, "Only %i cores are expected but core %i reports %s", gSessionData->mCores, cpu, result.mAction);
 384                         handleException();
 385                 }
 386
 387                 if (strcmp(result.mAction, "online") == 0) {
 388                         mBuffer.onlineCPU(currTime, currTime - gSessionData->mMonotonicStarted, cpu);
 389                         // Only call onlineCPU if prepareCPU succeeded
 390                         bool result = false;
 391                         int err = mCountersGroup.prepareCPU(cpu, &mMonitor);
 392                         if (err == PG_CPU_OFFLINE) {
 393                                 result = true;
 394                         } else if (err == PG_SUCCESS) {
 395                                 if (mCountersGroup.onlineCPU(currTime, cpu, true, &mBuffer)) {
 396                                         err = mIdleGroup.prepareCPU(cpu, &mMonitor);
 397                                         if (err == PG_CPU_OFFLINE) {
 398                                                 result = true;
 399                                         } else if (err == PG_SUCCESS) {
 400                                                 if (mIdleGroup.onlineCPU(currTime, cpu, true, &mBuffer)) {
 401                                                         result = true;
 402                                                 }
 403                                         }
 404                                 }
 405                         }
 406                         mBuffer.commit(currTime);
 407
 408                         gSessionData->readCpuInfo();
 409                         gSessionData->perf.coreName(currTime, &mSummary, cpu);
 410                         mSummary.commit(currTime);
 411                         return result;
 412                 } else if (strcmp(result.mAction, "offline") == 0) {
 413                         const bool result = mCountersGroup.offlineCPU(cpu) && mIdleGroup.offlineCPU(cpu);
 414                         mBuffer.offlineCPU(currTime, currTime - gSessionData->mMonotonicStarted, cpu);
 415                         return result;
 416                 }
 417         }
 418
 419         return true;
 420 }
 421
 422 void PerfSource::interrupt() {
 423         if (mInterruptFd >= 0) {
 424                 int8_t c = 0;
 425                 // Write to the pipe to wake the monitor which will cause mSessionIsActive to be reread
 426                 if (::write(mInterruptFd, &c, sizeof(c)) != sizeof(c)) {
 427                         logg->logError(__FILE__, __LINE__, "write failed");
 428                         handleException();
 429                 }
 430         }
 431 }
 432
 433 bool PerfSource::isDone () {
 434         return mBuffer.isDone() && mIsDone && mCountersBuf.isEmpty();
 435 }
 436
 437 void PerfSource::write (Sender *sender) {
 438         if (!mSummary.isDone()) {
 439                 mSummary.write(sender);
 440                 gSessionData->mSentSummary = true;
 441         }
 442         if (!mBuffer.isDone()) {
 443                 mBuffer.write(sender);
 444         }
 445         if (!mCountersBuf.send(sender)) {
 446                 logg->logError(__FILE__, __LINE__, "PerfBuffer::send failed");
 447                 handleException();
 448         }
 449 }