blob: 7aaf29851f9ad60252d96dbf92aee8c5f0b5a11d [file] [log] [blame]
Glenn Kasten11d8dfc2013-01-14 14:53:13 -08001/*
2 * Copyright (C) 2013 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 <binder/IMemory.h>
Glenn Kasten535e1612016-12-05 12:19:36 -080023#include <audio_utils/fifo.h>
Nicolas Rouletdcdfaec2017-02-14 10:18:39 -080024#include <utils/Mutex.h>
25#include <utils/threads.h>
Glenn Kasten11d8dfc2013-01-14 14:53:13 -080026
Nicolas Roulet40a44982017-02-03 13:39:57 -080027#include <vector>
28
Glenn Kasten11d8dfc2013-01-14 14:53:13 -080029namespace android {
30
Glenn Kasten4e01ef62013-07-11 14:29:59 -070031class String8;
32
Glenn Kasten11d8dfc2013-01-14 14:53:13 -080033class NBLog {
34
35public:
36
37class Writer;
38class Reader;
39
40private:
41
42enum Event {
43 EVENT_RESERVED,
44 EVENT_STRING, // ASCII string, not NUL-terminated
Nicolas Rouletdcdfaec2017-02-14 10:18:39 -080045 // TODO: make timestamp optional
Glenn Kasten11d8dfc2013-01-14 14:53:13 -080046 EVENT_TIMESTAMP, // clock_gettime(CLOCK_MONOTONIC)
Nicolas Roulet40a44982017-02-03 13:39:57 -080047 EVENT_INTEGER, // integer value entry
48 EVENT_FLOAT, // floating point value entry
49 EVENT_PID, // process ID and process name
50 EVENT_AUTHOR, // author index (present in merged logs) tracks entry's original log
Nicolas Rouletfe1e1442017-01-30 12:02:03 -080051 EVENT_START_FMT, // logFormat start event: entry includes format string, following
52 // entries contain format arguments
53 EVENT_END_FMT, // end of logFormat argument list
Glenn Kasten11d8dfc2013-01-14 14:53:13 -080054};
55
Nicolas Rouletcd5dd012017-02-13 12:09:28 -080056
57// ---------------------------------------------------------------------------
58// API for handling format entry operations
59
60// a formatted entry has the following structure:
61// * START_FMT entry, containing the format string
62// * author entry of the thread that generated it (optional, present in merged log)
63// * TIMESTAMP entry
64// * format arg1
65// * format arg2
66// * ...
67// * END_FMT entry
68
69class FormatEntry {
70public:
71 // build a Format Entry starting in the given pointer
72 class iterator;
73 explicit FormatEntry(const uint8_t *entry);
74 explicit FormatEntry(const iterator &it);
75
76 // entry representation in memory
77 struct entry {
78 const uint8_t type;
79 const uint8_t length;
80 const uint8_t data[0];
81 };
82
83 // entry tail representation (after data)
84 struct ending {
85 uint8_t length;
86 uint8_t next[0];
87 };
88
89 // entry iterator
90 class iterator {
91 public:
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -080092 iterator();
Nicolas Rouletcd5dd012017-02-13 12:09:28 -080093 iterator(const uint8_t *entry);
94 iterator(const iterator &other);
95
96 // dereference underlying entry
97 const entry& operator*() const;
98 const entry* operator->() const;
99 // advance to next entry
100 iterator& operator++(); // ++i
101 // back to previous entry
102 iterator& operator--(); // --i
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800103 iterator next() const;
104 iterator prev() const;
Nicolas Rouletcd5dd012017-02-13 12:09:28 -0800105 bool operator!=(const iterator &other) const;
106 int operator-(const iterator &other) const;
107
108 bool hasConsistentLength() const;
109 void copyTo(std::unique_ptr<audio_utils_fifo_writer> &dst) const;
110 void copyData(uint8_t *dst) const;
111
112 template<typename T>
113 inline const T& payload() {
Nicolas Rouletdcdfaec2017-02-14 10:18:39 -0800114 return *reinterpret_cast<const T *>(ptr + offsetof(entry, data));
Nicolas Rouletcd5dd012017-02-13 12:09:28 -0800115 }
116
117 private:
118 friend class FormatEntry;
119 const uint8_t *ptr;
120 };
121
122 // Entry's format string
123 const char* formatString() const;
124
125 // Enrty's format string length
126 size_t formatStringLength() const;
127
128 // Format arguments (excluding format string, timestamp and author)
129 iterator args() const;
130
131 // get format entry timestamp
132 timespec timestamp() const;
133
134 // entry's author index (-1 if none present)
135 // a Merger has a vector of Readers, author simply points to the index of the
136 // Reader that originated the entry
137 int author() const;
138
139 // copy entry, adding author before timestamp, returns size of original entry
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800140 iterator copyWithAuthor(std::unique_ptr<audio_utils_fifo_writer> &dst, int author) const;
Nicolas Rouletcd5dd012017-02-13 12:09:28 -0800141
142 iterator begin() const;
143
144private:
145 // copies ordinary entry from src to dst, and returns length of entry
146 // size_t copyEntry(audio_utils_fifo_writer *dst, const iterator &it);
147 const uint8_t *mEntry;
148};
149
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800150// ---------------------------------------------------------------------------
151
152// representation of a single log entry in private memory
153struct Entry {
154 Entry(Event event, const void *data, size_t length)
155 : mEvent(event), mLength(length), mData(data) { }
156 /*virtual*/ ~Entry() { }
157
158 int readAt(size_t offset) const;
159
160private:
161 friend class Writer;
162 Event mEvent; // event type
Glenn Kasten535e1612016-12-05 12:19:36 -0800163 uint8_t mLength; // length of additional data, 0 <= mLength <= kMaxLength
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800164 const void *mData; // event type-specific data
Glenn Kasten535e1612016-12-05 12:19:36 -0800165 static const size_t kMaxLength = 255;
166public:
Nicolas Rouletcd5dd012017-02-13 12:09:28 -0800167 // mEvent, mLength, mData[...], duplicate mLength
168 static const size_t kOverhead = sizeof(FormatEntry::entry) + sizeof(FormatEntry::ending);
169 // endind length of previous entry
170 static const size_t kPreviousLengthOffset = - sizeof(FormatEntry::ending) +
171 offsetof(FormatEntry::ending, length);
Nicolas Roulet40a44982017-02-03 13:39:57 -0800172};
173
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800174// representation of a single log entry in shared memory
175// byte[0] mEvent
176// byte[1] mLength
177// byte[2] mData[0]
178// ...
179// byte[2+i] mData[i]
180// ...
181// byte[2+mLength-1] mData[mLength-1]
182// byte[2+mLength] duplicate copy of mLength to permit reverse scan
183// byte[3+mLength] start of next log entry
184
Nicolas Rouletfe1e1442017-01-30 12:02:03 -0800185 static void appendInt(String8 *body, const void *data);
186 static void appendFloat(String8 *body, const void *data);
Nicolas Rouletc20cb502017-02-01 12:35:24 -0800187 static void appendPID(String8 *body, const void *data, size_t length);
Nicolas Rouletfe1e1442017-01-30 12:02:03 -0800188 static void appendTimestamp(String8 *body, const void *data);
Nicolas Roulet40a44982017-02-03 13:39:57 -0800189 static size_t fmtEntryLength(const uint8_t *data);
Nicolas Rouletfe1e1442017-01-30 12:02:03 -0800190
Glenn Kasten535e1612016-12-05 12:19:36 -0800191public:
192
193// Located in shared memory, must be POD.
194// Exactly one process must explicitly call the constructor or use placement new.
195// Since this is a POD, the destructor is empty and unnecessary to call it explicitly.
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800196struct Shared {
Glenn Kasten535e1612016-12-05 12:19:36 -0800197 Shared() /* mRear initialized via default constructor */ { }
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800198 /*virtual*/ ~Shared() { }
199
Glenn Kasten535e1612016-12-05 12:19:36 -0800200 audio_utils_fifo_index mRear; // index one byte past the end of most recent Entry
201 char mBuffer[0]; // circular buffer for entries
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800202};
203
204public:
205
206// ---------------------------------------------------------------------------
207
208// FIXME Timeline was intended to wrap Writer and Reader, but isn't actually used yet.
209// For now it is just a namespace for sharedSize().
210class Timeline : public RefBase {
211public:
212#if 0
213 Timeline(size_t size, void *shared = NULL);
214 virtual ~Timeline();
215#endif
216
Glenn Kastenfb1fdc92013-07-10 17:03:19 -0700217 // Input parameter 'size' is the desired size of the timeline in byte units.
218 // Returns the size rounded up to a power-of-2, plus the constant size overhead for indices.
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800219 static size_t sharedSize(size_t size);
220
221#if 0
222private:
223 friend class Writer;
224 friend class Reader;
225
226 const size_t mSize; // circular buffer size in bytes, must be a power of 2
227 bool mOwn; // whether I own the memory at mShared
228 Shared* const mShared; // pointer to shared memory
229#endif
230};
231
232// ---------------------------------------------------------------------------
233
234// Writer is thread-safe with respect to Reader, but not with respect to multiple threads
235// calling Writer methods. If you need multi-thread safety for writing, use LockedWriter.
236class Writer : public RefBase {
237public:
238 Writer(); // dummy nop implementation without shared memory
Glenn Kastenfb1fdc92013-07-10 17:03:19 -0700239
240 // Input parameter 'size' is the desired size of the timeline in byte units.
241 // The size of the shared memory must be at least Timeline::sharedSize(size).
Glenn Kasten535e1612016-12-05 12:19:36 -0800242 Writer(void *shared, size_t size);
243 Writer(const sp<IMemory>& iMemory, size_t size);
Glenn Kastenfb1fdc92013-07-10 17:03:19 -0700244
Glenn Kasten535e1612016-12-05 12:19:36 -0800245 virtual ~Writer();
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800246
247 virtual void log(const char *string);
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800248 virtual void logf(const char *fmt, ...) __attribute__ ((format (printf, 2, 3)));
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800249 virtual void logvf(const char *fmt, va_list ap);
250 virtual void logTimestamp();
Nicolas Rouletfe1e1442017-01-30 12:02:03 -0800251 virtual void logTimestamp(const struct timespec &ts);
252 virtual void logInteger(const int x);
253 virtual void logFloat(const float x);
254 virtual void logPID();
255 virtual void logFormat(const char *fmt, ...);
256 virtual void logVFormat(const char *fmt, va_list ap);
257 virtual void logStart(const char *fmt);
258 virtual void logEnd();
259
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800260
261 virtual bool isEnabled() const;
262
263 // return value for all of these is the previous isEnabled()
264 virtual bool setEnabled(bool enabled); // but won't enable if no shared memory
265 bool enable() { return setEnabled(true); }
266 bool disable() { return setEnabled(false); }
267
268 sp<IMemory> getIMemory() const { return mIMemory; }
269
270private:
Glenn Kasten535e1612016-12-05 12:19:36 -0800271 // 0 <= length <= kMaxLength
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800272 void log(Event event, const void *data, size_t length);
273 void log(const Entry *entry, bool trusted = false);
274
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800275 Shared* const mShared; // raw pointer to shared memory
Glenn Kasten535e1612016-12-05 12:19:36 -0800276 sp<IMemory> mIMemory; // ref-counted version, initialized in constructor and then const
277 audio_utils_fifo * const mFifo; // FIFO itself,
278 // non-NULL unless constructor fails
279 audio_utils_fifo_writer * const mFifoWriter; // used to write to FIFO,
280 // non-NULL unless dummy constructor used
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800281 bool mEnabled; // whether to actually log
Nicolas Rouletc20cb502017-02-01 12:35:24 -0800282
283 // cached pid and process name to use in %p format specifier
284 // total tag length is mPidTagSize and process name is not zero terminated
285 char *mPidTag;
286 size_t mPidTagSize;
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800287};
288
289// ---------------------------------------------------------------------------
290
291// Similar to Writer, but safe for multiple threads to call concurrently
292class LockedWriter : public Writer {
293public:
294 LockedWriter();
Glenn Kasten535e1612016-12-05 12:19:36 -0800295 LockedWriter(void *shared, size_t size);
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800296
297 virtual void log(const char *string);
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800298 virtual void logf(const char *fmt, ...) __attribute__ ((format (printf, 2, 3)));
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800299 virtual void logvf(const char *fmt, va_list ap);
300 virtual void logTimestamp();
Nicolas Rouletfe1e1442017-01-30 12:02:03 -0800301 virtual void logTimestamp(const struct timespec &ts);
302 virtual void logInteger(const int x);
303 virtual void logFloat(const float x);
304 virtual void logPID();
305 virtual void logStart(const char *fmt);
306 virtual void logEnd();
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800307
308 virtual bool isEnabled() const;
309 virtual bool setEnabled(bool enabled);
310
311private:
312 mutable Mutex mLock;
313};
314
315// ---------------------------------------------------------------------------
316
317class Reader : public RefBase {
318public:
Glenn Kastenfb1fdc92013-07-10 17:03:19 -0700319
Nicolas Roulet40a44982017-02-03 13:39:57 -0800320 // A snapshot of a readers buffer
321 class Snapshot {
322 public:
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800323 Snapshot() : mData(NULL), mLost(0) {}
Nicolas Roulet40a44982017-02-03 13:39:57 -0800324
325 Snapshot(size_t bufferSize) : mData(new uint8_t[bufferSize]) {}
326
327 ~Snapshot() { delete[] mData; }
328
329 // copy of the buffer
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800330 uint8_t *data() const { return mData; }
Nicolas Roulet40a44982017-02-03 13:39:57 -0800331
332 // amount of data lost (given by audio_utils_fifo_reader)
333 size_t lost() const { return mLost; }
334
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800335 // iterator to beginning of readable segment of snapshot
336 // data between begin and end has valid entries
337 FormatEntry::iterator begin() { return mBegin; }
338
339 // iterator to end of readable segment of snapshot
340 FormatEntry::iterator end() { return mEnd; }
341
342
Nicolas Roulet40a44982017-02-03 13:39:57 -0800343 private:
344 friend class Reader;
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800345 uint8_t *mData;
346 size_t mLost;
347 FormatEntry::iterator mBegin;
348 FormatEntry::iterator mEnd;
Nicolas Roulet40a44982017-02-03 13:39:57 -0800349 };
350
Glenn Kastenfb1fdc92013-07-10 17:03:19 -0700351 // Input parameter 'size' is the desired size of the timeline in byte units.
352 // The size of the shared memory must be at least Timeline::sharedSize(size).
Glenn Kasten535e1612016-12-05 12:19:36 -0800353 Reader(const void *shared, size_t size);
354 Reader(const sp<IMemory>& iMemory, size_t size);
Glenn Kastenfb1fdc92013-07-10 17:03:19 -0700355
Glenn Kasten535e1612016-12-05 12:19:36 -0800356 virtual ~Reader();
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800357
Nicolas Roulet40a44982017-02-03 13:39:57 -0800358 // get snapshot of readers fifo buffer, effectively consuming the buffer
359 std::unique_ptr<Snapshot> getSnapshot();
360 // dump a particular snapshot of the reader
361 void dump(int fd, size_t indent, Snapshot & snap);
362 // dump the current content of the reader's buffer
363 void dump(int fd, size_t indent = 0);
364 bool isIMemory(const sp<IMemory>& iMemory) const;
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800365
366private:
Glenn Kasten535e1612016-12-05 12:19:36 -0800367 /*const*/ Shared* const mShared; // raw pointer to shared memory, actually const but not
368 // declared as const because audio_utils_fifo() constructor
369 sp<IMemory> mIMemory; // ref-counted version, assigned only in constructor
Glenn Kasten4e01ef62013-07-11 14:29:59 -0700370 int mFd; // file descriptor
371 int mIndent; // indentation level
Glenn Kasten535e1612016-12-05 12:19:36 -0800372 audio_utils_fifo * const mFifo; // FIFO itself,
373 // non-NULL unless constructor fails
374 audio_utils_fifo_reader * const mFifoReader; // used to read from FIFO,
375 // non-NULL unless constructor fails
Glenn Kasten4e01ef62013-07-11 14:29:59 -0700376
377 void dumpLine(const String8& timestamp, String8& body);
Nicolas Rouletcd5dd012017-02-13 12:09:28 -0800378
379 FormatEntry::iterator handleFormat(const FormatEntry &fmtEntry,
380 String8 *timestamp,
381 String8 *body);
Nicolas Roulet40a44982017-02-03 13:39:57 -0800382 // dummy method for handling absent author entry
383 virtual size_t handleAuthor(const FormatEntry &fmtEntry, String8 *body) { return 0; }
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800384
Nicolas Roulet6ea1d7e2017-02-14 16:17:31 -0800385 // Searches for the last entry of type <type> in the range [front, back)
386 // back has to be entry-aligned. Returns nullptr if none enconuntered.
387 static uint8_t *findLastEntryOfType(uint8_t *front, uint8_t *back, uint8_t type);
388
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800389 static const size_t kSquashTimestamp = 5; // squash this many or more adjacent timestamps
390};
391
Nicolas Roulet40a44982017-02-03 13:39:57 -0800392// Wrapper for a reader with a name. Contains a pointer to the reader and a pointer to the name
393class NamedReader {
394public:
395 NamedReader() { mName[0] = '\0'; } // for Vector
396 NamedReader(const sp<NBLog::Reader>& reader, const char *name) :
397 mReader(reader)
398 { strlcpy(mName, name, sizeof(mName)); }
399 ~NamedReader() { }
400 const sp<NBLog::Reader>& reader() const { return mReader; }
401 const char* name() const { return mName; }
402
403private:
404 sp<NBLog::Reader> mReader;
405 static const size_t kMaxName = 32;
406 char mName[kMaxName];
407};
408
409// ---------------------------------------------------------------------------
410
411class Merger : public RefBase {
412public:
413 Merger(const void *shared, size_t size);
414
415 virtual ~Merger() {}
416
417 void addReader(const NamedReader &reader);
418 // TODO add removeReader
419 void merge();
420 const std::vector<NamedReader> *getNamedReaders() const;
421private:
422 // vector of the readers the merger is supposed to merge from.
423 // every reader reads from a writer's buffer
424 std::vector<NamedReader> mNamedReaders;
425 uint8_t *mBuffer;
426 Shared * const mShared;
427 std::unique_ptr<audio_utils_fifo> mFifo;
428 std::unique_ptr<audio_utils_fifo_writer> mFifoWriter;
429
430 static struct timespec getTimestamp(const uint8_t *data);
431};
432
433class MergeReader : public Reader {
434public:
435 MergeReader(const void *shared, size_t size, Merger &merger);
436private:
437 const std::vector<NamedReader> *mNamedReaders;
438 // handle author entry by looking up the author's name and appending it to the body
439 // returns number of bytes read from fmtEntry
440 size_t handleAuthor(const FormatEntry &fmtEntry, String8 *body);
441};
442
Nicolas Rouletdcdfaec2017-02-14 10:18:39 -0800443// MergeThread is a thread that contains a Merger. It works as a retriggerable one-shot:
444// when triggered, it awakes for a lapse of time, during which it periodically merges; if
445// retriggered, the timeout is reset.
446// The thread is triggered on AudioFlinger binder activity.
447class MergeThread : public Thread {
448public:
449 MergeThread(Merger &merger);
450 virtual ~MergeThread() override;
451
452 // Reset timeout and activate thread to merge periodically if it's idle
453 void wakeup();
454
455 // Set timeout period until the merging thread goes idle again
456 void setTimeoutUs(int time);
457
458private:
459 virtual bool threadLoop() override;
460
461 // the merger who actually does the work of merging the logs
462 Merger& mMerger;
463
464 // mutex for the condition variable
465 Mutex mMutex;
466
467 // condition variable to activate merging on timeout >= 0
468 Condition mCond;
469
470 // time left until the thread blocks again (in microseconds)
471 int mTimeoutUs;
472
473 // merging period when the thread is awake
474 static const int kThreadSleepPeriodUs = 1000000 /*1s*/;
475
476 // initial timeout value when triggered
477 static const int kThreadWakeupPeriodUs = 3000000 /*3s*/;
478};
479
Glenn Kasten11d8dfc2013-01-14 14:53:13 -0800480}; // class NBLog
481
482} // namespace android
483
484#endif // ANDROID_MEDIA_NBLOG_H