1 /*
2  * Copyright 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 // #define LOG_NDEBUG 0
18 #define LOG_TAG "audio_utils_PowerLog"
19 #include <log/log.h>
20 
21 #include <audio_utils/PowerLog.h>
22 
23 #include <algorithm>
24 #include <iomanip>
25 #include <math.h>
26 #include <sstream>
27 #include <stdint.h>
28 #include <unistd.h>
29 #include <vector>
30 
31 #include <audio_utils/clock.h>
32 #include <audio_utils/LogPlot.h>
33 #include <audio_utils/power.h>
34 
35 namespace android {
36 
PowerLogBase(uint32_t sampleRate,uint32_t channelCount,audio_format_t format,size_t entries,size_t framesPerEntry)37 PowerLogBase::PowerLogBase(uint32_t sampleRate,
38         uint32_t channelCount,
39         audio_format_t format,
40         size_t entries,
41         size_t framesPerEntry)
42     : mSampleRate(sampleRate)
43     , mChannelCount(channelCount)
44     , mFormat(format)
45     , mFramesPerEntry(framesPerEntry)
46     , mEntryTimeNs(framesPerEntry * 1e9 / sampleRate)
47     , mMaxTimeSlipNs(std::min((int64_t)200'000'000, mEntryTimeNs))
48     , mEntries(entries)
49 {
50     (void)mFormat; // currently unused, for future use
51     LOG_ALWAYS_FATAL_IF(!audio_utils_is_compute_power_format_supported(format),
52             "unsupported format: %#x", format);
53 }
54 
processEnergy(size_t frames,float energy,int64_t nowNs)55 void PowerLogBase::processEnergy(size_t frames, float energy, int64_t nowNs) {
56     // For big entries (i.e. 1 second+) we want to ensure we don't have new data
57     // accumulating into a previous energy segment.
58     if (mCurrentTime > 0
59             && nowNs > mCurrentTime + mCurrentFrames * 1e9 / mSampleRate + mMaxTimeSlipNs) {
60         flushEntry();
61     }
62 
63     mCurrentEnergy += energy;
64 
65     // if we are in a zero run, do not advance.
66     if (mCurrentEnergy == 0.f && mConsecutiveZeroes > 0) return;
67 
68     mCurrentFrames += frames;
69     if (mCurrentTime == 0) {
70         mCurrentTime = nowNs;
71     }
72 
73     ALOGV("%s: nowNs:%lld, frames:%zu, mCurrentEnergy:%f, mCurrentFrames:%zu",
74             __func__, (long long)nowNs, frames, mCurrentEnergy, mCurrentFrames);
75     if (mCurrentFrames < mFramesPerEntry) return;
76 
77     flushEntry();
78 }
79 
dumpToString(const char * prefix,size_t lines,int64_t limitNs,bool logPlot) const80 std::string PowerLogBase::dumpToString(
81         const char *prefix, size_t lines, int64_t limitNs, bool logPlot) const
82 {
83     const size_t maxColumns = 10;
84     const size_t numberOfEntries = mEntries.size();
85     if (lines == 0) lines = SIZE_MAX;
86 
87     // compute where to start logging
88     enum {
89         AT_END,
90         IN_SIGNAL,
91     } state = IN_SIGNAL;
92     size_t count = 1;
93     size_t column = 0;
94     size_t nonzeros = 0;
95     ssize_t offset; // TODO doesn't dump if # entries exceeds SSIZE_MAX
96     for (offset = 0; offset < (ssize_t)numberOfEntries && count < lines; ++offset) {
97         const size_t idx = (mIdx + numberOfEntries - offset - 1) % numberOfEntries;
98                                                                                 // reverse direction
99         const int64_t time = mEntries[idx].first;
100         const float energy = mEntries[idx].second;
101 
102         if (state == AT_END) {
103             if (energy == 0.f) {
104                 ALOGV("two zeroes detected");
105                 break; // normally single zero terminated - two zeroes means no more data.
106             }
107             state = IN_SIGNAL;
108         } else { // IN_SIGNAL
109             if (energy == 0.f) {
110                 if (column != 0) {
111                     column = 0;
112                     ++count;
113                 }
114                 state = AT_END;
115                 continue;
116             }
117         }
118         if (column == 0 && time < limitNs) {
119             break;
120         }
121         ++nonzeros;
122         if (++column == maxColumns) {
123             column = 0;
124             // TODO ideally we would peek the previous entry to see if it is 0
125             // to ensure we properly put in a starting signal bracket.
126             // We don't do that because it would complicate the logic here.
127             ++count;
128         }
129     }
130     if (offset > 0) {
131         --offset;
132     }
133     // We accumulate the log info into a string, and write to the fd once.
134     std::stringstream ss;
135     ss << std::fixed << std::setprecision(1);
136     // ss << std::scientific;
137     if (nonzeros == 0) {
138         ss << prefix << "Signal power history: (none)\n";
139     } else {
140         // First value is power, second value is whether value is start of
141         // a new time stamp.
142         std::vector<std::pair<float, bool>> plotEntries;
143         const float timeResolution = mFramesPerEntry * 1000.f / mSampleRate;
144         ss << prefix << "Signal power history (resolution: " << timeResolution << " ms):\n";
145 
146         size_t column = 0;
147         bool first = true;
148         bool start = false;
149         float cumulative = 0.f;
150         for (; offset >= 0; --offset) {
151             const size_t idx = (mIdx + numberOfEntries - offset - 1) % numberOfEntries;
152             const int64_t time = mEntries[idx].first;
153             const float energy = mEntries[idx].second;
154 
155             if (energy == 0.f) {
156                 if (!first) {
157                     ss << " ] sum(" << audio_utils_power_from_energy(cumulative) << ")";
158                     // Add an entry to denote the start of a new time stamp series.
159                     if (!plotEntries.empty()) {
160                         // First value should be between min and max of all graph entries
161                         // so that it doesn't mess with y-axis scaling.
162                         plotEntries.emplace_back(plotEntries.back().first, true);
163                     }
164                 }
165                 cumulative = 0.f;
166                 column = 0;
167                 start = true;
168                 continue;
169             }
170             if (column == 0) {
171                 // print time if at start of column
172                 if (!first) {
173                     ss << "\n";
174                 }
175                 ss << prefix << " " << audio_utils_time_string_from_ns(time).time
176                         << (start ? ": [ ": ":   ");
177                 first = false;
178                 start = false;
179             }  else {
180                 ss << " ";
181             }
182             if (++column >= maxColumns) {
183                 column = 0;
184             }
185 
186             cumulative += energy;
187             // convert energy to power and print
188             const float power =
189                     audio_utils_power_from_energy(energy / (mChannelCount * mFramesPerEntry));
190             ss << std::setw(6) << power;
191             ALOGV("state: %d %lld %f", state, (long long)time, power);
192             // Add an entry to the ASCII art power log graph.
193             // false indicates the value doesn't have a new series time stamp.
194             plotEntries.emplace_back(power, false);
195         }
196         if (logPlot) {
197             ss << "\n" << audio_utils_log_plot(plotEntries.begin(), plotEntries.end());
198         }
199         ss << "\n";
200     }
201     return ss.str();
202 }
203 
flushEntry()204 void PowerLogBase::flushEntry() {
205     // We store the data as normalized energy per sample. The energy sequence is
206     // zero terminated. Consecutive zero entries are ignored.
207     if (mCurrentEnergy == 0.f) {
208         if (mConsecutiveZeroes++ == 0) {
209             mEntries[mIdx++] = std::make_pair(mCurrentTime, 0.f);
210             // zero terminate the signal sequence.
211         }
212     } else {
213         mConsecutiveZeroes = 0;
214         mEntries[mIdx++] = std::make_pair(mCurrentTime, mCurrentEnergy);
215         ALOGV("writing %lld %f", (long long)mCurrentTime, mCurrentEnergy);
216     }
217     if (mIdx >= mEntries.size()) {
218         mIdx -= mEntries.size();
219     }
220     mCurrentTime = 0;
221     mCurrentEnergy = 0;
222     mCurrentFrames = 0;
223 }
224 
log(const void * buffer,size_t frames,int64_t nowNs)225 void PowerLog::log(const void *buffer, size_t frames, int64_t nowNs) {
226     if (frames == 0) return;
227     std::lock_guard <std::mutex> guard(mMutex);
228 
229     const size_t bytes_per_sample = audio_bytes_per_sample(mFormat);
230     while (true) {
231         // limit the number of frames to process from the requirements
232         // of each log base.
233         size_t processFrames = mBase[0]->framesToProcess(frames);
234         for (size_t i = 1; i < std::size(mBase); ++i) {
235             processFrames = std::min(processFrames, mBase[i]->framesToProcess(frames));
236         }
237         const float energy = audio_utils_compute_energy_mono(buffer, mFormat,
238                                                              processFrames * mChannelCount);
239         for (const auto& base : mBase) {
240             base->processEnergy(processFrames, energy, nowNs);
241         }
242         frames -= processFrames;
243         if (frames == 0) return;
244         buffer = (const uint8_t *) buffer + processFrames * mChannelCount * bytes_per_sample;
245         nowNs += processFrames * NANOS_PER_SECOND / mSampleRate;
246     }
247 }
248 
dumpToString(const char * prefix,size_t lines,int64_t limitNs,bool logPlot) const249 std::string PowerLog::dumpToString(
250         const char *prefix, size_t lines, int64_t limitNs, bool logPlot) const
251 {
252     // Determine how to distribute lines among the logs.
253     const size_t logs = mBase.size();
254     std::vector<size_t> sublines(logs);
255     size_t start = 0;
256 
257     if (lines > 0) {
258         // we compute the # of lines per PowerLogBase starting from
259         // largest time granularity / resolution to the finest resolution.
260         //
261         // The largest granularity has the fewest lines, doubling
262         // as the granularity gets finer.
263         // The finest 2 levels have identical number of lines.
264         size_t norm = 1 << (logs - 1);
265         if (logs > 2) norm += (1 << (logs - 2)) - 1;
266         size_t alloc = 0;
267         for (size_t i = 0; i < logs - 1; ++i) {
268             const size_t l = (1 << i) * lines / norm;
269             if (l == 0) {
270                 start = i + 1;
271             } else {
272                 sublines[i] = l;
273                 alloc += l;
274             }
275         }
276         sublines[logs - 1] = lines - alloc;
277     }
278 
279     // Our PowerLogBase vector is stored from finest granularity / resolution to largest
280     // granularity.  We dump the logs in reverse order (logs - 1 - "index").
281     std::string s = mBase[logs - 1 - start]->dumpToString(
282             prefix, sublines[start], limitNs, start == logs - 1 ? logPlot : false);
283     for (size_t i = start + 1; i < logs; ++i) {
284         s.append(mBase[logs - 1 - i]->dumpToString(
285                 prefix, sublines[i], limitNs, i == logs - 1 ? logPlot : false));
286     }
287     return s;
288 }
289 
dump(int fd,const char * prefix,size_t lines,int64_t limitNs,bool logPlot) const290 status_t PowerLog::dump(
291         int fd, const char *prefix, size_t lines, int64_t limitNs, bool logPlot) const
292 {
293     // Since dumpToString and write are thread safe, this function
294     // is conceptually thread-safe but simultaneous calls to dump
295     // by different threads to the same file descriptor may not write
296     // the two logs in time order.
297     const std::string s = dumpToString(prefix, lines, limitNs, logPlot);
298     if (s.size() > 0 && write(fd, s.c_str(), s.size()) < 0) {
299         return -errno;
300     }
301     return NO_ERROR;
302 }
303 
304 } // namespace android
305 
306 using namespace android;
307 
power_log_create(uint32_t sample_rate,uint32_t channel_count,audio_format_t format,size_t entries,size_t frames_per_entry)308 power_log_t *power_log_create(uint32_t sample_rate,
309         uint32_t channel_count, audio_format_t format, size_t entries, size_t frames_per_entry)
310 {
311     if (!audio_utils_is_compute_power_format_supported(format)) {
312         return nullptr;
313     }
314     return reinterpret_cast<power_log_t *>
315             (new(std::nothrow)
316                     PowerLog(sample_rate, channel_count, format, entries, frames_per_entry));
317 }
318 
power_log_log(power_log_t * power_log,const void * buffer,size_t frames,int64_t now_ns)319 void power_log_log(power_log_t *power_log,
320         const void *buffer, size_t frames, int64_t now_ns)
321 {
322     if (power_log == nullptr) {
323         return;
324     }
325     reinterpret_cast<PowerLog *>(power_log)->log(buffer, frames, now_ns);
326 }
327 
power_log_dump(power_log_t * power_log,int fd,const char * prefix,size_t lines,int64_t limit_ns)328 int power_log_dump(
329         power_log_t *power_log, int fd, const char *prefix, size_t lines, int64_t limit_ns)
330 {
331     if (power_log == nullptr) {
332         return BAD_VALUE;
333     }
334     return reinterpret_cast<PowerLog *>(power_log)->dump(fd, prefix, lines, limit_ns);
335 }
336 
power_log_destroy(power_log_t * power_log)337 void power_log_destroy(power_log_t *power_log)
338 {
339     delete reinterpret_cast<PowerLog *>(power_log);
340 }
341