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) const110 std::string PowerLog::dumpToString(const char *prefix, size_t lines, int64_t limitNs) const
111 {
112     std::lock_guard<std::mutex> guard(mLock);
113 
114     const size_t maxColumns = 10;
115     const size_t numberOfEntries = mEntries.size();
116     if (lines == 0) lines = SIZE_MAX;
117 
118     // compute where to start logging
119     enum {
120         AT_END,
121         IN_SIGNAL,
122     } state = IN_SIGNAL;
123     size_t count = 1;
124     size_t column = 0;
125     size_t nonzeros = 0;
126     ssize_t offset; // TODO doesn't dump if # entries exceeds SSIZE_MAX
127     for (offset = 0; offset < (ssize_t)numberOfEntries && count < lines; ++offset) {
128         const size_t idx = (mIdx + numberOfEntries - offset - 1) % numberOfEntries;
129                                                                                 // reverse direction
130         const int64_t time = mEntries[idx].first;
131         const float energy = mEntries[idx].second;
132 
133         if (state == AT_END) {
134             if (energy == 0.f) {
135                 ALOGV("two zeroes detected");
136                 break; // normally single zero terminated - two zeroes means no more data.
137             }
138             state = IN_SIGNAL;
139         } else { // IN_SIGNAL
140             if (energy == 0.f) {
141                 if (column != 0) {
142                     column = 0;
143                     ++count;
144                 }
145                 state = AT_END;
146                 continue;
147             }
148         }
149         if (column == 0 && time < limitNs) {
150             break;
151         }
152         ++nonzeros;
153         if (++column == maxColumns) {
154             column = 0;
155             // TODO ideally we would peek the previous entry to see if it is 0
156             // to ensure we properly put in a starting signal bracket.
157             // We don't do that because it would complicate the logic here.
158             ++count;
159         }
160     }
161     if (offset > 0) {
162         --offset;
163     }
164     // We accumulate the log info into a string, and write to the fd once.
165     std::stringstream ss;
166     ss << std::fixed << std::setprecision(1);
167     // ss << std::scientific;
168     if (nonzeros == 0) {
169         ss << prefix << "Signal power history: (none)\n";
170     } else {
171         // First value is power, second value is whether value is start of
172         // a new time stamp.
173         std::vector<std::pair<float, bool>> plotEntries;
174         ss << prefix << "Signal power history:\n";
175 
176         size_t column = 0;
177         bool first = true;
178         bool start = false;
179         float cumulative = 0.f;
180         for (; offset >= 0; --offset) {
181             const size_t idx = (mIdx + numberOfEntries - offset - 1) % numberOfEntries;
182             const int64_t time = mEntries[idx].first;
183             const float energy = mEntries[idx].second;
184 
185             if (energy == 0.f) {
186                 if (!first) {
187                     ss << " ] sum(" << audio_utils_power_from_energy(cumulative) << ")";
188                     // Add an entry to denote the start of a new time stamp series.
189                     if (!plotEntries.empty()) {
190                         // First value should be between min and max of all graph entries
191                         // so that it doesn't mess with y-axis scaling.
192                         plotEntries.emplace_back(plotEntries.back().first, true);
193                     }
194                 }
195                 cumulative = 0.f;
196                 column = 0;
197                 start = true;
198                 continue;
199             }
200             if (column == 0) {
201                 // print time if at start of column
202                 if (!first) {
203                     ss << "\n";
204                 }
205                 ss << prefix << " " << audio_utils_time_string_from_ns(time).time
206                         << (start ? ": [ ": ":   ");
207                 first = false;
208                 start = false;
209             }  else {
210                 ss << " ";
211             }
212             if (++column >= maxColumns) {
213                 column = 0;
214             }
215 
216             cumulative += energy;
217             // convert energy to power and print
218             const float power =
219                     audio_utils_power_from_energy(energy / (mChannelCount * mFramesPerEntry));
220             ss << std::setw(6) << power;
221             ALOGV("state: %d %lld %f", state, (long long)time, power);
222             // Add an entry to the ASCII art power log graph.
223             // false indicates the value doesn't have a new series time stamp.
224             plotEntries.emplace_back(power, false);
225         }
226         ss << "\n" << audio_utils_log_plot(plotEntries.begin(), plotEntries.end());
227         ss << "\n";
228     }
229     return ss.str();
230 }
231 
dump(int fd,const char * prefix,size_t lines,int64_t limitNs) const232 status_t PowerLog::dump(int fd, const char *prefix, size_t lines, int64_t limitNs) const
233 {
234     // Since dumpToString and write are thread safe, this function
235     // is conceptually thread-safe but simultaneous calls to dump
236     // by different threads to the same file descriptor may not write
237     // the two logs in time order.
238     const std::string s = dumpToString(prefix, lines, limitNs);
239     if (s.size() > 0 && write(fd, s.c_str(), s.size()) < 0) {
240         return -errno;
241     }
242     return NO_ERROR;
243 }
244 
245 } // namespace android
246 
247 using namespace android;
248 
power_log_create(uint32_t sample_rate,uint32_t channel_count,audio_format_t format,size_t entries,size_t frames_per_entry)249 power_log_t *power_log_create(uint32_t sample_rate,
250         uint32_t channel_count, audio_format_t format, size_t entries, size_t frames_per_entry)
251 {
252     if (!audio_utils_is_compute_power_format_supported(format)) {
253         return nullptr;
254     }
255     return reinterpret_cast<power_log_t *>
256             (new(std::nothrow)
257                     PowerLog(sample_rate, channel_count, format, entries, frames_per_entry));
258 }
259 
power_log_log(power_log_t * power_log,const void * buffer,size_t frames,int64_t now_ns)260 void power_log_log(power_log_t *power_log,
261         const void *buffer, size_t frames, int64_t now_ns)
262 {
263     if (power_log == nullptr) {
264         return;
265     }
266     reinterpret_cast<PowerLog *>(power_log)->log(buffer, frames, now_ns);
267 }
268 
power_log_dump(power_log_t * power_log,int fd,const char * prefix,size_t lines,int64_t limit_ns)269 int power_log_dump(
270         power_log_t *power_log, int fd, const char *prefix, size_t lines, int64_t limit_ns)
271 {
272     if (power_log == nullptr) {
273         return BAD_VALUE;
274     }
275     return reinterpret_cast<PowerLog *>(power_log)->dump(fd, prefix, lines, limit_ns);
276 }
277 
power_log_destroy(power_log_t * power_log)278 void power_log_destroy(power_log_t *power_log)
279 {
280     delete reinterpret_cast<PowerLog *>(power_log);
281 }
282