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 <algorithm>
22 #include <iomanip>
23 #include <math.h>
24 #include <sstream>
25 #include <stdint.h>
26 #include <unistd.h>
27 #include <vector>
28 
29 #include <audio_utils/clock.h>
30 #include <audio_utils/LogPlot.h>
31 #include <audio_utils/power.h>
32 #include <audio_utils/PowerLog.h>
33 
34 namespace android {
35 
36 // TODO move to separate file
37 template <typename T, size_t N>
array_size(const T (&)[N])38 constexpr size_t array_size(const T(&)[N])
39 {
40     return N;
41 }
42 
PowerLog(uint32_t sampleRate,uint32_t channelCount,audio_format_t format,size_t entries,size_t framesPerEntry)43 PowerLog::PowerLog(uint32_t sampleRate,
44         uint32_t channelCount,
45         audio_format_t format,
46         size_t entries,
47         size_t framesPerEntry)
48     : mCurrentTime(0)
49     , mCurrentEnergy(0)
50     , mCurrentFrames(0)
51     , mIdx(0)
52     , mConsecutiveZeroes(0)
53     , mSampleRate(sampleRate)
54     , mChannelCount(channelCount)
55     , mFormat(format)
56     , mFramesPerEntry(framesPerEntry)
57     , mEntries(entries)
58 {
59     (void)mSampleRate; // currently unused, for future use
60     LOG_ALWAYS_FATAL_IF(!audio_utils_is_compute_power_format_supported(format),
61             "unsupported format: %#x", format);
62 }
63 
log(const void * buffer,size_t frames,int64_t nowNs)64 void PowerLog::log(const void *buffer, size_t frames, int64_t nowNs)
65 {
66     std::lock_guard<std::mutex> guard(mLock);
67 
68     const size_t bytes_per_sample = audio_bytes_per_sample(mFormat);
69     while (frames > 0) {
70         // check partial computation
71         size_t required = mFramesPerEntry - mCurrentFrames;
72         size_t process = std::min(required, frames);
73 
74         if (mCurrentTime == 0) {
75             mCurrentTime = nowNs;
76         }
77         mCurrentEnergy +=
78                 audio_utils_compute_energy_mono(buffer, mFormat, process * mChannelCount);
79         mCurrentFrames += process;
80 
81         ALOGV("nowNs:%lld, required:%zu, process:%zu, mCurrentEnergy:%f, mCurrentFrames:%zu",
82                 (long long)nowNs, required, process, mCurrentEnergy, mCurrentFrames);
83         if (process < required) {
84             return;
85         }
86 
87         // We store the data as normalized energy per sample. The energy sequence is
88         // zero terminated. Consecutive zeroes are ignored.
89         if (mCurrentEnergy == 0.f) {
90             if (mConsecutiveZeroes++ == 0) {
91                 mEntries[mIdx++] = std::make_pair(nowNs, 0.f);
92                 // zero terminate the signal sequence.
93             }
94         } else {
95             mConsecutiveZeroes = 0;
96             mEntries[mIdx++] = std::make_pair(mCurrentTime, mCurrentEnergy);
97             ALOGV("writing %lld %f", (long long)mCurrentTime, mCurrentEnergy);
98         }
99         if (mIdx >= mEntries.size()) {
100             mIdx -= mEntries.size();
101         }
102         mCurrentTime = 0;
103         mCurrentEnergy = 0;
104         mCurrentFrames = 0;
105         frames -= process;
106         buffer = (const uint8_t *)buffer + mCurrentFrames * mChannelCount * bytes_per_sample;
107     }
108 }
109 
dumpToString(const char * prefix,size_t lines,int64_t limitNs,bool logPlot) const110 std::string PowerLog::dumpToString(
111         const char *prefix, size_t lines, int64_t limitNs, bool logPlot) const
112 {
113     std::lock_guard<std::mutex> guard(mLock);
114 
115     const size_t maxColumns = 10;
116     const size_t numberOfEntries = mEntries.size();
117     if (lines == 0) lines = SIZE_MAX;
118 
119     // compute where to start logging
120     enum {
121         AT_END,
122         IN_SIGNAL,
123     } state = IN_SIGNAL;
124     size_t count = 1;
125     size_t column = 0;
126     size_t nonzeros = 0;
127     ssize_t offset; // TODO doesn't dump if # entries exceeds SSIZE_MAX
128     for (offset = 0; offset < (ssize_t)numberOfEntries && count < lines; ++offset) {
129         const size_t idx = (mIdx + numberOfEntries - offset - 1) % numberOfEntries;
130                                                                                 // reverse direction
131         const int64_t time = mEntries[idx].first;
132         const float energy = mEntries[idx].second;
133 
134         if (state == AT_END) {
135             if (energy == 0.f) {
136                 ALOGV("two zeroes detected");
137                 break; // normally single zero terminated - two zeroes means no more data.
138             }
139             state = IN_SIGNAL;
140         } else { // IN_SIGNAL
141             if (energy == 0.f) {
142                 if (column != 0) {
143                     column = 0;
144                     ++count;
145                 }
146                 state = AT_END;
147                 continue;
148             }
149         }
150         if (column == 0 && time < limitNs) {
151             break;
152         }
153         ++nonzeros;
154         if (++column == maxColumns) {
155             column = 0;
156             // TODO ideally we would peek the previous entry to see if it is 0
157             // to ensure we properly put in a starting signal bracket.
158             // We don't do that because it would complicate the logic here.
159             ++count;
160         }
161     }
162     if (offset > 0) {
163         --offset;
164     }
165     // We accumulate the log info into a string, and write to the fd once.
166     std::stringstream ss;
167     ss << std::fixed << std::setprecision(1);
168     // ss << std::scientific;
169     if (nonzeros == 0) {
170         ss << prefix << "Signal power history: (none)\n";
171     } else {
172         // First value is power, second value is whether value is start of
173         // a new time stamp.
174         std::vector<std::pair<float, bool>> plotEntries;
175         ss << prefix << "Signal power history:\n";
176 
177         size_t column = 0;
178         bool first = true;
179         bool start = false;
180         float cumulative = 0.f;
181         for (; offset >= 0; --offset) {
182             const size_t idx = (mIdx + numberOfEntries - offset - 1) % numberOfEntries;
183             const int64_t time = mEntries[idx].first;
184             const float energy = mEntries[idx].second;
185 
186             if (energy == 0.f) {
187                 if (!first) {
188                     ss << " ] sum(" << audio_utils_power_from_energy(cumulative) << ")";
189                     // Add an entry to denote the start of a new time stamp series.
190                     if (!plotEntries.empty()) {
191                         // First value should be between min and max of all graph entries
192                         // so that it doesn't mess with y-axis scaling.
193                         plotEntries.emplace_back(plotEntries.back().first, true);
194                     }
195                 }
196                 cumulative = 0.f;
197                 column = 0;
198                 start = true;
199                 continue;
200             }
201             if (column == 0) {
202                 // print time if at start of column
203                 if (!first) {
204                     ss << "\n";
205                 }
206                 ss << prefix << " " << audio_utils_time_string_from_ns(time).time
207                         << (start ? ": [ ": ":   ");
208                 first = false;
209                 start = false;
210             }  else {
211                 ss << " ";
212             }
213             if (++column >= maxColumns) {
214                 column = 0;
215             }
216 
217             cumulative += energy;
218             // convert energy to power and print
219             const float power =
220                     audio_utils_power_from_energy(energy / (mChannelCount * mFramesPerEntry));
221             ss << std::setw(6) << power;
222             ALOGV("state: %d %lld %f", state, (long long)time, power);
223             // Add an entry to the ASCII art power log graph.
224             // false indicates the value doesn't have a new series time stamp.
225             plotEntries.emplace_back(power, false);
226         }
227         if (logPlot) {
228             ss << "\n" << audio_utils_log_plot(plotEntries.begin(), plotEntries.end());
229         }
230         ss << "\n";
231     }
232     return ss.str();
233 }
234 
dump(int fd,const char * prefix,size_t lines,int64_t limitNs,bool logPlot) const235 status_t PowerLog::dump(
236         int fd, const char *prefix, size_t lines, int64_t limitNs, bool logPlot) const
237 {
238     // Since dumpToString and write are thread safe, this function
239     // is conceptually thread-safe but simultaneous calls to dump
240     // by different threads to the same file descriptor may not write
241     // the two logs in time order.
242     const std::string s = dumpToString(prefix, lines, limitNs, logPlot);
243     if (s.size() > 0 && write(fd, s.c_str(), s.size()) < 0) {
244         return -errno;
245     }
246     return NO_ERROR;
247 }
248 
249 } // namespace android
250 
251 using namespace android;
252 
power_log_create(uint32_t sample_rate,uint32_t channel_count,audio_format_t format,size_t entries,size_t frames_per_entry)253 power_log_t *power_log_create(uint32_t sample_rate,
254         uint32_t channel_count, audio_format_t format, size_t entries, size_t frames_per_entry)
255 {
256     if (!audio_utils_is_compute_power_format_supported(format)) {
257         return nullptr;
258     }
259     return reinterpret_cast<power_log_t *>
260             (new(std::nothrow)
261                     PowerLog(sample_rate, channel_count, format, entries, frames_per_entry));
262 }
263 
power_log_log(power_log_t * power_log,const void * buffer,size_t frames,int64_t now_ns)264 void power_log_log(power_log_t *power_log,
265         const void *buffer, size_t frames, int64_t now_ns)
266 {
267     if (power_log == nullptr) {
268         return;
269     }
270     reinterpret_cast<PowerLog *>(power_log)->log(buffer, frames, now_ns);
271 }
272 
power_log_dump(power_log_t * power_log,int fd,const char * prefix,size_t lines,int64_t limit_ns)273 int power_log_dump(
274         power_log_t *power_log, int fd, const char *prefix, size_t lines, int64_t limit_ns)
275 {
276     if (power_log == nullptr) {
277         return BAD_VALUE;
278     }
279     return reinterpret_cast<PowerLog *>(power_log)->dump(fd, prefix, lines, limit_ns);
280 }
281 
power_log_destroy(power_log_t * power_log)282 void power_log_destroy(power_log_t *power_log)
283 {
284     delete reinterpret_cast<PowerLog *>(power_log);
285 }
286