1/* 2 * Copyright (C) 2017 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17// Non-blocking event logger intended for safe communication between processes via shared memory 18 19#ifndef ANDROID_MEDIA_NBLOG_H 20#define ANDROID_MEDIA_NBLOG_H 21 22#include <deque> 23#include <map> 24#include <set> 25#include <vector> 26 27#include <audio_utils/fifo.h> 28#include <binder/IMemory.h> 29#include <media/nblog/PerformanceAnalysis.h> 30#include <media/nblog/ReportPerformance.h> 31#include <utils/Mutex.h> 32#include <utils/threads.h> 33 34namespace android { 35 36class String8; 37 38class NBLog { 39 40public: 41 42 using log_hash_t = ReportPerformance::log_hash_t; 43 44 // FIXME Everything needed for client (writer API and registration) should be isolated 45 // from the rest of the implementation. 46 class Writer; 47 class Reader; 48 49 enum Event : uint8_t { 50 EVENT_RESERVED, 51 EVENT_STRING, // ASCII string, not NUL-terminated 52 // TODO: make timestamp optional 53 EVENT_TIMESTAMP, // clock_gettime(CLOCK_MONOTONIC) 54 EVENT_INTEGER, // integer value entry 55 EVENT_FLOAT, // floating point value entry 56 EVENT_PID, // process ID and process name 57 EVENT_AUTHOR, // author index (present in merged logs) tracks entry's 58 // original log 59 EVENT_START_FMT, // logFormat start event: entry includes format string, 60 // following entries contain format arguments 61 EVENT_HASH, // unique HASH of log origin, originates from hash of file name 62 // and line number 63 EVENT_HISTOGRAM_ENTRY_TS, // single datum for timestamp histogram 64 EVENT_AUDIO_STATE, // audio on/off event: logged on FastMixer::onStateChange call 65 EVENT_END_FMT, // end of logFormat argument list 66 67 EVENT_UPPER_BOUND, // to check for invalid events 68 }; 69 70private: 71 72 // --------------------------------------------------------------------------- 73 // API for handling format entry operations 74 75 // a formatted entry has the following structure: 76 // * START_FMT entry, containing the format string 77 // * TIMESTAMP entry 78 // * HASH entry 79 // * author entry of the thread that generated it (optional, present in merged log) 80 // * format arg1 81 // * format arg2 82 // * ... 83 // * END_FMT entry 84 85 // entry representation in memory 86 struct entry { 87 const uint8_t type; 88 const uint8_t length; 89 const uint8_t data[0]; 90 }; 91 92 // entry tail representation (after data) 93 struct ending { 94 uint8_t length; 95 uint8_t next[0]; 96 }; 97 98 // entry iterator 99 class EntryIterator { 100 public: 101 EntryIterator(); 102 explicit EntryIterator(const uint8_t *entry); 103 EntryIterator(const EntryIterator &other); 104 105 // dereference underlying entry 106 const entry& operator*() const; 107 const entry* operator->() const; 108 // advance to next entry 109 EntryIterator& operator++(); // ++i 110 // back to previous entry 111 EntryIterator& operator--(); // --i 112 EntryIterator next() const; 113 EntryIterator prev() const; 114 bool operator!=(const EntryIterator &other) const; 115 int operator-(const EntryIterator &other) const; 116 117 bool hasConsistentLength() const; 118 void copyTo(std::unique_ptr<audio_utils_fifo_writer> &dst) const; 119 void copyData(uint8_t *dst) const; 120 121 template<typename T> 122 inline const T& payload() { 123 return *reinterpret_cast<const T *>(ptr + offsetof(entry, data)); 124 } 125 126 inline operator const uint8_t*() const { 127 return ptr; 128 } 129 130 private: 131 const uint8_t *ptr; 132 }; 133 134 class AbstractEntry { 135 public: 136 137 // Entry starting in the given pointer 138 explicit AbstractEntry(const uint8_t *entry); 139 virtual ~AbstractEntry() {} 140 141 // build concrete entry of appropriate class from pointer 142 static std::unique_ptr<AbstractEntry> buildEntry(const uint8_t *ptr); 143 144 // get format entry timestamp 145 virtual int64_t timestamp() const = 0; 146 147 // get format entry's unique id 148 virtual log_hash_t hash() const = 0; 149 150 // entry's author index (-1 if none present) 151 // a Merger has a vector of Readers, author simply points to the index of the 152 // Reader that originated the entry 153 // TODO consider changing to uint32_t 154 virtual int author() const = 0; 155 156 // copy entry, adding author before timestamp, returns iterator to end of entry 157 virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst, 158 int author) const = 0; 159 160 protected: 161 // copies ordinary entry from src to dst, and returns length of entry 162 // size_t copyEntry(audio_utils_fifo_writer *dst, const iterator &it); 163 const uint8_t *mEntry; 164 }; 165 166 class FormatEntry : public AbstractEntry { 167 public: 168 // explicit FormatEntry(const EntryIterator &it); 169 explicit FormatEntry(const uint8_t *ptr) : AbstractEntry(ptr) {} 170 virtual ~FormatEntry() {} 171 172 EntryIterator begin() const; 173 174 // Entry's format string 175 const char* formatString() const; 176 177 // Enrty's format string length 178 size_t formatStringLength() const; 179 180 // Format arguments (excluding format string, timestamp and author) 181 EntryIterator args() const; 182 183 // get format entry timestamp 184 virtual int64_t timestamp() const override; 185 186 // get format entry's unique id 187 virtual log_hash_t hash() const override; 188 189 // entry's author index (-1 if none present) 190 // a Merger has a vector of Readers, author simply points to the index of the 191 // Reader that originated the entry 192 virtual int author() const override; 193 194 // copy entry, adding author before timestamp, returns size of original entry 195 virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst, 196 int author) const override; 197 198 }; 199 200 class HistogramEntry : public AbstractEntry { 201 public: 202 explicit HistogramEntry(const uint8_t *ptr) : AbstractEntry(ptr) { 203 } 204 virtual ~HistogramEntry() {} 205 206 virtual int64_t timestamp() const override; 207 208 virtual log_hash_t hash() const override; 209 210 virtual int author() const override; 211 212 virtual EntryIterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst, 213 int author) const override; 214 215 }; 216 217 // --------------------------------------------------------------------------- 218 219 // representation of a single log entry in private memory 220 struct Entry { 221 Entry(Event event, const void *data, size_t length) 222 : mEvent(event), mLength(length), mData(data) { } 223 /*virtual*/ ~Entry() { } 224 225 // used during writing to format Entry information as follows: 226 // [type][length][data ... ][length] 227 int copyEntryDataAt(size_t offset) const; 228 229 private: 230 friend class Writer; 231 Event mEvent; // event type 232 uint8_t mLength; // length of additional data, 0 <= mLength <= kMaxLength 233 const void *mData; // event type-specific data 234 static const size_t kMaxLength = 255; 235 public: 236 // mEvent, mLength, mData[...], duplicate mLength 237 static const size_t kOverhead = sizeof(entry) + sizeof(ending); 238 // endind length of previous entry 239 static const ssize_t kPreviousLengthOffset = - sizeof(ending) + 240 offsetof(ending, length); 241 }; 242 243 struct HistTsEntry { 244 log_hash_t hash; 245 int64_t ts; 246 }; //TODO __attribute__((packed)); 247 248 struct HistTsEntryWithAuthor { 249 log_hash_t hash; 250 int64_t ts; 251 int author; 252 }; //TODO __attribute__((packed)); 253 254 struct HistIntEntry { 255 log_hash_t hash; 256 int value; 257 }; //TODO __attribute__((packed)); 258 259 // representation of a single log entry in shared memory 260 // byte[0] mEvent 261 // byte[1] mLength 262 // byte[2] mData[0] 263 // ... 264 // byte[2+i] mData[i] 265 // ... 266 // byte[2+mLength-1] mData[mLength-1] 267 // byte[2+mLength] duplicate copy of mLength to permit reverse scan 268 // byte[3+mLength] start of next log entry 269 270 static void appendInt(String8 *body, const void *data); 271 static void appendFloat(String8 *body, const void *data); 272 static void appendPID(String8 *body, const void *data, size_t length); 273 static void appendTimestamp(String8 *body, const void *data); 274 static size_t fmtEntryLength(const uint8_t *data); 275 static String8 bufferDump(const uint8_t *buffer, size_t size); 276 static String8 bufferDump(const EntryIterator &it); 277public: 278 279 // Located in shared memory, must be POD. 280 // Exactly one process must explicitly call the constructor or use placement new. 281 // Since this is a POD, the destructor is empty and unnecessary to call it explicitly. 282 struct Shared { 283 Shared() /* mRear initialized via default constructor */ { } 284 /*virtual*/ ~Shared() { } 285 286 audio_utils_fifo_index mRear; // index one byte past the end of most recent Entry 287 char mBuffer[0]; // circular buffer for entries 288 }; 289 290public: 291 292 // --------------------------------------------------------------------------- 293 294 // FIXME Timeline was intended to wrap Writer and Reader, but isn't actually used yet. 295 // For now it is just a namespace for sharedSize(). 296 class Timeline : public RefBase { 297 public: 298#if 0 299 Timeline(size_t size, void *shared = NULL); 300 virtual ~Timeline(); 301#endif 302 303 // Input parameter 'size' is the desired size of the timeline in byte units. 304 // Returns the size rounded up to a power-of-2, plus the constant size overhead for indices. 305 static size_t sharedSize(size_t size); 306 307#if 0 308 private: 309 friend class Writer; 310 friend class Reader; 311 312 const size_t mSize; // circular buffer size in bytes, must be a power of 2 313 bool mOwn; // whether I own the memory at mShared 314 Shared* const mShared; // pointer to shared memory 315#endif 316 }; 317 318 // --------------------------------------------------------------------------- 319 320 // Writer is thread-safe with respect to Reader, but not with respect to multiple threads 321 // calling Writer methods. If you need multi-thread safety for writing, use LockedWriter. 322 class Writer : public RefBase { 323 public: 324 Writer(); // dummy nop implementation without shared memory 325 326 // Input parameter 'size' is the desired size of the timeline in byte units. 327 // The size of the shared memory must be at least Timeline::sharedSize(size). 328 Writer(void *shared, size_t size); 329 Writer(const sp<IMemory>& iMemory, size_t size); 330 331 virtual ~Writer(); 332 333 // FIXME needs comments, and some should be private 334 virtual void log(const char *string); 335 virtual void logf(const char *fmt, ...) __attribute__ ((format (printf, 2, 3))); 336 virtual void logvf(const char *fmt, va_list ap); 337 virtual void logTimestamp(); 338 virtual void logTimestamp(const int64_t ts); 339 virtual void logInteger(const int x); 340 virtual void logFloat(const float x); 341 virtual void logPID(); 342 virtual void logFormat(const char *fmt, log_hash_t hash, ...); 343 virtual void logVFormat(const char *fmt, log_hash_t hash, va_list ap); 344 virtual void logStart(const char *fmt); 345 virtual void logEnd(); 346 virtual void logHash(log_hash_t hash); 347 virtual void logEventHistTs(Event event, log_hash_t hash); 348 349 virtual bool isEnabled() const; 350 351 // return value for all of these is the previous isEnabled() 352 virtual bool setEnabled(bool enabled); // but won't enable if no shared memory 353 bool enable() { return setEnabled(true); } 354 bool disable() { return setEnabled(false); } 355 356 sp<IMemory> getIMemory() const { return mIMemory; } 357 358 private: 359 // 0 <= length <= kMaxLength 360 // writes a single Entry to the FIFO 361 void log(Event event, const void *data, size_t length); 362 // checks validity of an event before calling log above this one 363 void log(const Entry *entry, bool trusted = false); 364 365 Shared* const mShared; // raw pointer to shared memory 366 sp<IMemory> mIMemory; // ref-counted version, initialized in constructor 367 // and then const 368 audio_utils_fifo * const mFifo; // FIFO itself, non-NULL 369 // unless constructor fails 370 audio_utils_fifo_writer * const mFifoWriter; // used to write to FIFO, non-NULL 371 // unless dummy constructor used 372 bool mEnabled; // whether to actually log 373 374 // cached pid and process name to use in %p format specifier 375 // total tag length is mPidTagSize and process name is not zero terminated 376 char *mPidTag; 377 size_t mPidTagSize; 378 }; 379 380 // --------------------------------------------------------------------------- 381 382 // Similar to Writer, but safe for multiple threads to call concurrently 383 class LockedWriter : public Writer { 384 public: 385 LockedWriter(); 386 LockedWriter(void *shared, size_t size); 387 388 virtual void log(const char *string); 389 virtual void logf(const char *fmt, ...) __attribute__ ((format (printf, 2, 3))); 390 virtual void logvf(const char *fmt, va_list ap); 391 virtual void logTimestamp(); 392 virtual void logTimestamp(const int64_t ts); 393 virtual void logInteger(const int x); 394 virtual void logFloat(const float x); 395 virtual void logPID(); 396 virtual void logStart(const char *fmt); 397 virtual void logEnd(); 398 virtual void logHash(log_hash_t hash); 399 400 virtual bool isEnabled() const; 401 virtual bool setEnabled(bool enabled); 402 403 private: 404 mutable Mutex mLock; 405 }; 406 407 // --------------------------------------------------------------------------- 408 409 class Reader : public RefBase { 410 public: 411 // A snapshot of a readers buffer 412 // This is raw data. No analysis has been done on it 413 class Snapshot { 414 public: 415 Snapshot() : mData(NULL), mLost(0) {} 416 417 Snapshot(size_t bufferSize) : mData(new uint8_t[bufferSize]) {} 418 419 ~Snapshot() { delete[] mData; } 420 421 // copy of the buffer 422 uint8_t *data() const { return mData; } 423 424 // amount of data lost (given by audio_utils_fifo_reader) 425 size_t lost() const { return mLost; } 426 427 // iterator to beginning of readable segment of snapshot 428 // data between begin and end has valid entries 429 EntryIterator begin() { return mBegin; } 430 431 // iterator to end of readable segment of snapshot 432 EntryIterator end() { return mEnd; } 433 434 private: 435 friend class MergeReader; 436 friend class Reader; 437 uint8_t *mData; 438 size_t mLost; 439 EntryIterator mBegin; 440 EntryIterator mEnd; 441 }; 442 443 // Input parameter 'size' is the desired size of the timeline in byte units. 444 // The size of the shared memory must be at least Timeline::sharedSize(size). 445 Reader(const void *shared, size_t size); 446 Reader(const sp<IMemory>& iMemory, size_t size); 447 448 virtual ~Reader(); 449 450 // get snapshot of readers fifo buffer, effectively consuming the buffer 451 std::unique_ptr<Snapshot> getSnapshot(); 452 453 bool isIMemory(const sp<IMemory>& iMemory) const; 454 455 protected: 456 // print a summary of the performance to the console 457 void dumpLine(const String8& timestamp, String8& body); 458 EntryIterator handleFormat(const FormatEntry &fmtEntry, 459 String8 *timestamp, 460 String8 *body); 461 int mFd; // file descriptor 462 int mIndent; // indentation level 463 int mLost; // bytes of data lost before buffer was read 464 465 private: 466 static const std::set<Event> startingTypes; 467 static const std::set<Event> endingTypes; 468 469 // declared as const because audio_utils_fifo() constructor 470 sp<IMemory> mIMemory; // ref-counted version, assigned only in constructor 471 472 /*const*/ Shared* const mShared; // raw pointer to shared memory, actually const but not 473 audio_utils_fifo * const mFifo; // FIFO itself, 474 // non-NULL unless constructor fails 475 audio_utils_fifo_reader * const mFifoReader; // used to read from FIFO, 476 // non-NULL unless constructor fails 477 478 // Searches for the last entry of type <type> in the range [front, back) 479 // back has to be entry-aligned. Returns nullptr if none enconuntered. 480 static const uint8_t *findLastEntryOfTypes(const uint8_t *front, const uint8_t *back, 481 const std::set<Event> &types); 482 483 // dummy method for handling absent author entry 484 virtual void handleAuthor(const AbstractEntry& /*fmtEntry*/, String8* /*body*/) {} 485 }; 486 487 // Wrapper for a reader with a name. Contains a pointer to the reader and a pointer to the name 488 class NamedReader { 489 public: 490 NamedReader() { mName[0] = '\0'; } // for Vector 491 NamedReader(const sp<NBLog::Reader>& reader, const char *name) : 492 mReader(reader) 493 { strlcpy(mName, name, sizeof(mName)); } 494 ~NamedReader() { } 495 const sp<NBLog::Reader>& reader() const { return mReader; } 496 const char* name() const { return mName; } 497 498 private: 499 sp<NBLog::Reader> mReader; 500 static const size_t kMaxName = 32; 501 char mName[kMaxName]; 502 }; 503 504 // --------------------------------------------------------------------------- 505 506 // This class is used to read data from each thread's individual FIFO in shared memory 507 // and write it to a single FIFO in local memory. 508 class Merger : public RefBase { 509 public: 510 Merger(const void *shared, size_t size); 511 512 virtual ~Merger() {} 513 514 void addReader(const NamedReader &reader); 515 // TODO add removeReader 516 void merge(); 517 518 // FIXME This is returning a reference to a shared variable that needs a lock 519 const std::vector<NamedReader>& getNamedReaders() const; 520 521 private: 522 // vector of the readers the merger is supposed to merge from. 523 // every reader reads from a writer's buffer 524 // FIXME Needs to be protected by a lock 525 std::vector<NamedReader> mNamedReaders; 526 527 Shared * const mShared; // raw pointer to shared memory 528 std::unique_ptr<audio_utils_fifo> mFifo; // FIFO itself 529 std::unique_ptr<audio_utils_fifo_writer> mFifoWriter; // used to write to FIFO 530 }; 531 532 // This class has a pointer to the FIFO in local memory which stores the merged 533 // data collected by NBLog::Merger from all NamedReaders. It is used to process 534 // this data and write the result to PerformanceAnalysis. 535 class MergeReader : public Reader { 536 public: 537 MergeReader(const void *shared, size_t size, Merger &merger); 538 539 void dump(int fd, int indent = 0); 540 // process a particular snapshot of the reader 541 void getAndProcessSnapshot(Snapshot & snap); 542 // call getSnapshot of the content of the reader's buffer and process the data 543 void getAndProcessSnapshot(); 544 545 private: 546 // FIXME Needs to be protected by a lock, 547 // because even though our use of it is read-only there may be asynchronous updates 548 const std::vector<NamedReader>& mNamedReaders; 549 550 // analyzes, compresses and stores the merged data 551 // contains a separate instance for every author (thread), and for every source file 552 // location within each author 553 ReportPerformance::PerformanceAnalysisMap mThreadPerformanceAnalysis; 554 555 // handle author entry by looking up the author's name and appending it to the body 556 // returns number of bytes read from fmtEntry 557 void handleAuthor(const AbstractEntry &fmtEntry, String8 *body); 558 }; 559 560 // MergeThread is a thread that contains a Merger. It works as a retriggerable one-shot: 561 // when triggered, it awakes for a lapse of time, during which it periodically merges; if 562 // retriggered, the timeout is reset. 563 // The thread is triggered on AudioFlinger binder activity. 564 class MergeThread : public Thread { 565 public: 566 MergeThread(Merger &merger, MergeReader &mergeReader); 567 virtual ~MergeThread() override; 568 569 // Reset timeout and activate thread to merge periodically if it's idle 570 void wakeup(); 571 572 // Set timeout period until the merging thread goes idle again 573 void setTimeoutUs(int time); 574 575 private: 576 virtual bool threadLoop() override; 577 578 // the merger who actually does the work of merging the logs 579 Merger& mMerger; 580 581 // the mergereader used to process data merged by mMerger 582 MergeReader& mMergeReader; 583 584 // mutex for the condition variable 585 Mutex mMutex; 586 587 // condition variable to activate merging on timeout >= 0 588 Condition mCond; 589 590 // time left until the thread blocks again (in microseconds) 591 int mTimeoutUs; 592 593 // merging period when the thread is awake 594 static const int kThreadSleepPeriodUs = 1000000 /*1s*/; 595 596 // initial timeout value when triggered 597 static const int kThreadWakeupPeriodUs = 3000000 /*3s*/; 598 }; 599 600}; // class NBLog 601 602// TODO put somewhere else 603static inline int64_t get_monotonic_ns() { 604 timespec ts; 605 if (clock_gettime(CLOCK_MONOTONIC, &ts) == 0) { 606 return (uint64_t) ts.tv_sec * 1000 * 1000 * 1000 + ts.tv_nsec; 607 } 608 return 0; // should not happen. 609} 610 611} // namespace android 612 613#endif // ANDROID_MEDIA_NBLOG_H 614