tools/gator/daemon/PerfSource.cpp

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