input_sync_writer.cc 15 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411
  1. // Copyright (c) 2012 The Chromium Authors. All rights reserved.
  2. // Use of this source code is governed by a BSD-style license that can be
  3. // found in the LICENSE file.
  4. #include "services/audio/input_sync_writer.h"
  5. #include <algorithm>
  6. #include <utility>
  7. #include "base/format_macros.h"
  8. #include "base/logging.h"
  9. #include "base/metrics/histogram_functions.h"
  10. #include "base/strings/stringprintf.h"
  11. #include "base/trace_event/trace_event.h"
  12. #include "build/build_config.h"
  13. namespace audio {
  14. namespace {
  15. // Used to log if any audio glitches have been detected during an audio session.
  16. // Elements in this enum should not be added, deleted or rearranged.
  17. enum class AudioGlitchResult {
  18. kNoGlitches = 0,
  19. kGlitches = 1,
  20. kMaxValue = kGlitches
  21. };
  22. } // namespace
  23. InputSyncWriter::OverflowData::OverflowData(
  24. double volume,
  25. bool key_pressed,
  26. base::TimeTicks capture_time,
  27. std::unique_ptr<media::AudioBus> audio_bus)
  28. : volume_(volume),
  29. key_pressed_(key_pressed),
  30. capture_time_(capture_time),
  31. audio_bus_(std::move(audio_bus)) {}
  32. InputSyncWriter::OverflowData::~OverflowData() {}
  33. InputSyncWriter::OverflowData::OverflowData(InputSyncWriter::OverflowData&&) =
  34. default;
  35. InputSyncWriter::OverflowData& InputSyncWriter::OverflowData::operator=(
  36. InputSyncWriter::OverflowData&& other) = default;
  37. InputSyncWriter::InputSyncWriter(
  38. base::RepeatingCallback<void(const std::string&)> log_callback,
  39. base::MappedReadOnlyRegion shared_memory,
  40. std::unique_ptr<base::CancelableSyncSocket> socket,
  41. uint32_t shared_memory_segment_count,
  42. const media::AudioParameters& params)
  43. : log_callback_(std::move(log_callback)),
  44. socket_(std::move(socket)),
  45. shared_memory_region_(std::move(shared_memory.region)),
  46. shared_memory_mapping_(std::move(shared_memory.mapping)),
  47. shared_memory_segment_size_(
  48. (CHECK(shared_memory_segment_count > 0),
  49. shared_memory_mapping_.size() / shared_memory_segment_count)),
  50. creation_time_(base::TimeTicks::Now()),
  51. audio_bus_memory_size_(media::AudioBus::CalculateMemorySize(params)) {
  52. // We use CHECKs since this class is used for IPC.
  53. DCHECK(log_callback_);
  54. CHECK(socket_);
  55. CHECK(shared_memory_region_.IsValid());
  56. CHECK(shared_memory_mapping_.IsValid());
  57. CHECK_EQ(shared_memory_segment_size_ * shared_memory_segment_count,
  58. shared_memory_mapping_.size());
  59. CHECK_EQ(shared_memory_segment_size_,
  60. audio_bus_memory_size_ + sizeof(media::AudioInputBufferParameters));
  61. DVLOG(1) << "shared memory size: " << shared_memory_mapping_.size();
  62. DVLOG(1) << "shared memory segment count: " << shared_memory_segment_count;
  63. DVLOG(1) << "audio bus memory size: " << audio_bus_memory_size_;
  64. audio_buses_.resize(shared_memory_segment_count);
  65. // Create vector of audio buses by wrapping existing blocks of memory.
  66. uint8_t* ptr = static_cast<uint8_t*>(shared_memory_mapping_.memory());
  67. CHECK(ptr);
  68. for (auto& bus : audio_buses_) {
  69. CHECK_EQ(0U, reinterpret_cast<uintptr_t>(ptr) &
  70. (media::AudioBus::kChannelAlignment - 1));
  71. media::AudioInputBuffer* buffer =
  72. reinterpret_cast<media::AudioInputBuffer*>(ptr);
  73. bus = media::AudioBus::WrapMemory(params, buffer->audio);
  74. ptr += shared_memory_segment_size_;
  75. }
  76. }
  77. InputSyncWriter::~InputSyncWriter() {
  78. // We log the following:
  79. // - Percentage of data written to fifo (and not to shared memory).
  80. // - Percentage of data dropped (fifo reached max size or socket buffer full).
  81. // - Glitch yes/no (at least 1 drop).
  82. //
  83. // Subtract 'trailing' counts that will happen if the renderer process was
  84. // killed or e.g. the page refreshed while the input device was open etc.
  85. // This trims off the end of both the error and write counts so that we
  86. // preserve the proportion of counts before the teardown period. We pick
  87. // the largest trailing count as the time we consider that the trailing errors
  88. // begun, and subract that from the total write count.
  89. DCHECK_LE(trailing_write_to_fifo_count_, write_to_fifo_count_);
  90. DCHECK_LE(trailing_write_to_fifo_count_, write_count_);
  91. DCHECK_LE(trailing_write_error_count_, write_error_count_);
  92. DCHECK_LE(trailing_write_error_count_, write_count_);
  93. write_to_fifo_count_ -= trailing_write_to_fifo_count_;
  94. write_error_count_ -= trailing_write_error_count_;
  95. write_count_ -=
  96. std::max(trailing_write_to_fifo_count_, trailing_write_error_count_);
  97. if (write_count_ == 0)
  98. return;
  99. base::UmaHistogramPercentage("Media.AudioCapturerMissedReadDeadline",
  100. 100.0 * write_to_fifo_count_ / write_count_);
  101. base::UmaHistogramPercentage("Media.AudioCapturerDroppedData",
  102. 100.0 * write_error_count_ / write_count_);
  103. base::UmaHistogramEnumeration("Media.AudioCapturerAudioGlitches",
  104. write_error_count_ == 0
  105. ? AudioGlitchResult::kNoGlitches
  106. : AudioGlitchResult::kGlitches);
  107. const int kPermilleScaling = 1000;
  108. // 10%: if we have more that 10% of callbacks having issues, the details are
  109. // not very interesting any more, so we just log all those cases together to
  110. // have a better resolution for lower values.
  111. const int kHistogramRange = kPermilleScaling / 10;
  112. // 30 s for 10 ms buffers.
  113. const int kShortStreamMaxCallbackCount = 3000;
  114. const std::string suffix =
  115. write_count_ < kShortStreamMaxCallbackCount ? "Short" : "Long";
  116. int missed_deadline =
  117. std::ceil(kPermilleScaling * static_cast<double>(write_to_fifo_count_) /
  118. write_count_);
  119. base::UmaHistogramCustomCounts(
  120. "Media.AudioCapturerMissedReadDeadline2." + suffix,
  121. std::min(missed_deadline, kHistogramRange), 0, kHistogramRange + 1, 100);
  122. int dropped_data =
  123. std::ceil(kPermilleScaling * static_cast<double>(write_error_count_) /
  124. write_count_);
  125. base::UmaHistogramCustomCounts("Media.AudioCapturerDroppedData2." + suffix,
  126. std::min(dropped_data, kHistogramRange), 0,
  127. kHistogramRange + 1, 100);
  128. std::string log_string = base::StringPrintf(
  129. "AISW: number of detected audio glitches: %" PRIuS " out of %" PRIuS,
  130. write_error_count_, write_count_);
  131. log_callback_.Run(log_string);
  132. }
  133. // static
  134. std::unique_ptr<InputSyncWriter> InputSyncWriter::Create(
  135. base::RepeatingCallback<void(const std::string&)> log_callback,
  136. uint32_t shared_memory_segment_count,
  137. const media::AudioParameters& params,
  138. base::CancelableSyncSocket* foreign_socket) {
  139. // Having no shared memory doesn't make sense, so fail creation in that case.
  140. if (shared_memory_segment_count == 0)
  141. return nullptr;
  142. base::CheckedNumeric<uint32_t> requested_memory_size =
  143. ComputeAudioInputBufferSizeChecked(params, shared_memory_segment_count);
  144. if (!requested_memory_size.IsValid())
  145. return nullptr;
  146. // Make sure we can share the memory read-only with the client.
  147. auto shared_memory = base::ReadOnlySharedMemoryRegion::Create(
  148. requested_memory_size.ValueOrDie());
  149. if (!shared_memory.IsValid())
  150. return nullptr;
  151. auto socket = std::make_unique<base::CancelableSyncSocket>();
  152. if (!base::CancelableSyncSocket::CreatePair(socket.get(), foreign_socket)) {
  153. return nullptr;
  154. }
  155. return std::make_unique<InputSyncWriter>(
  156. std::move(log_callback), std::move(shared_memory), std::move(socket),
  157. shared_memory_segment_count, params);
  158. }
  159. base::ReadOnlySharedMemoryRegion InputSyncWriter::TakeSharedMemoryRegion() {
  160. DCHECK(shared_memory_region_.IsValid());
  161. return std::move(shared_memory_region_);
  162. }
  163. void InputSyncWriter::Write(const media::AudioBus* data,
  164. double volume,
  165. bool key_pressed,
  166. base::TimeTicks capture_time) {
  167. TRACE_EVENT1("audio", "InputSyncWriter::Write", "capture time (ms)",
  168. (capture_time - base::TimeTicks()).InMillisecondsF());
  169. ++write_count_;
  170. CheckTimeSinceLastWrite();
  171. // Check that the renderer side has read data so that we don't overwrite data
  172. // that hasn't been read yet. The renderer side sends a signal over the socket
  173. // each time it has read data. Here, we read those verifications before
  174. // writing. We verify that each buffer index is in sequence.
  175. size_t number_of_indices_available = socket_->Peek() / sizeof(uint32_t);
  176. if (number_of_indices_available > 0) {
  177. auto indices = std::make_unique<uint32_t[]>(number_of_indices_available);
  178. size_t bytes_received = socket_->Receive(
  179. &indices[0], number_of_indices_available * sizeof(indices[0]));
  180. CHECK_EQ(number_of_indices_available * sizeof(indices[0]), bytes_received);
  181. for (size_t i = 0; i < number_of_indices_available; ++i) {
  182. ++next_read_buffer_index_;
  183. CHECK_EQ(indices[i], next_read_buffer_index_);
  184. CHECK_GT(number_of_filled_segments_, 0u);
  185. --number_of_filled_segments_;
  186. }
  187. }
  188. bool write_error = !WriteDataFromFifoToSharedMemory();
  189. // Write the current data to the shared memory if there is room, otherwise
  190. // put it in the fifo.
  191. if (number_of_filled_segments_ < audio_buses_.size()) {
  192. WriteParametersToCurrentSegment(volume, key_pressed, capture_time);
  193. // Copy data into shared memory using pre-allocated audio buses.
  194. data->CopyTo(audio_buses_[current_segment_id_].get());
  195. if (!SignalDataWrittenAndUpdateCounters())
  196. write_error = true;
  197. trailing_write_to_fifo_count_ = 0;
  198. } else {
  199. if (!PushDataToFifo(data, volume, key_pressed, capture_time))
  200. write_error = true;
  201. ++write_to_fifo_count_;
  202. ++trailing_write_to_fifo_count_;
  203. }
  204. // Increase write error counts if error, or reset the trailing error counter
  205. // if all write operations went well (no data dropped).
  206. if (write_error) {
  207. ++write_error_count_;
  208. ++trailing_write_error_count_;
  209. TRACE_EVENT_INSTANT0("audio", "InputSyncWriter write error",
  210. TRACE_EVENT_SCOPE_THREAD);
  211. } else {
  212. trailing_write_error_count_ = 0;
  213. }
  214. }
  215. void InputSyncWriter::Close() {
  216. socket_->Close();
  217. }
  218. void InputSyncWriter::CheckTimeSinceLastWrite() {
  219. #if !BUILDFLAG(IS_ANDROID)
  220. static const base::TimeDelta kLogDelayThreadhold = base::Milliseconds(500);
  221. base::TimeTicks new_write_time = base::TimeTicks::Now();
  222. std::ostringstream oss;
  223. if (last_write_time_.is_null()) {
  224. // This is the first time Write is called.
  225. base::TimeDelta interval = new_write_time - creation_time_;
  226. oss << "AISW::Write: audio input data received for the first time: delay "
  227. "= "
  228. << interval.InMilliseconds() << "ms";
  229. } else {
  230. base::TimeDelta interval = new_write_time - last_write_time_;
  231. if (interval > kLogDelayThreadhold) {
  232. oss << "AISW::Write: audio input data delay unexpectedly long: delay = "
  233. << interval.InMilliseconds() << "ms";
  234. }
  235. }
  236. const std::string log_message = oss.str();
  237. if (!log_message.empty()) {
  238. log_callback_.Run(log_message);
  239. }
  240. last_write_time_ = new_write_time;
  241. #endif
  242. }
  243. bool InputSyncWriter::PushDataToFifo(const media::AudioBus* data,
  244. double volume,
  245. bool key_pressed,
  246. base::TimeTicks capture_time) {
  247. TRACE_EVENT1("audio", "InputSyncWriter::PushDataToFifo", "capture time (ms)",
  248. (capture_time - base::TimeTicks()).InMillisecondsF());
  249. if (overflow_data_.size() == kMaxOverflowBusesSize) {
  250. // We use |write_error_count_| for capping number of log messages.
  251. // |write_error_count_| also includes socket Send() errors, but those should
  252. // be rare.
  253. TRACE_EVENT_INSTANT0("audio", "InputSyncWriter::PushDataToFifo - overflow",
  254. TRACE_EVENT_SCOPE_THREAD);
  255. if (write_error_count_ <= 50 && write_error_count_ % 10 == 0) {
  256. static const char* error_message = "AISW: No room in fifo.";
  257. LOG(WARNING) << error_message;
  258. log_callback_.Run(error_message);
  259. if (write_error_count_ == 50) {
  260. static const char* cap_error_message =
  261. "AISW: Log cap reached, suppressing further fifo overflow logs.";
  262. LOG(WARNING) << cap_error_message;
  263. log_callback_.Run(error_message);
  264. }
  265. }
  266. return false;
  267. }
  268. if (overflow_data_.empty()) {
  269. static const char* message = "AISW: Starting to use fifo.";
  270. log_callback_.Run(message);
  271. }
  272. // Push data to fifo.
  273. std::unique_ptr<media::AudioBus> audio_bus =
  274. media::AudioBus::Create(data->channels(), data->frames());
  275. data->CopyTo(audio_bus.get());
  276. overflow_data_.emplace_back(volume, key_pressed, capture_time,
  277. std::move(audio_bus));
  278. DCHECK_LE(overflow_data_.size(), static_cast<size_t>(kMaxOverflowBusesSize));
  279. return true;
  280. }
  281. bool InputSyncWriter::WriteDataFromFifoToSharedMemory() {
  282. TRACE_EVENT0("audio", "InputSyncWriter::WriteDataFromFifoToSharedMemory");
  283. if (overflow_data_.empty())
  284. return true;
  285. const size_t segment_count = audio_buses_.size();
  286. bool write_error = false;
  287. auto data_it = overflow_data_.begin();
  288. while (data_it != overflow_data_.end() &&
  289. number_of_filled_segments_ < segment_count) {
  290. // Write parameters to shared memory.
  291. WriteParametersToCurrentSegment(data_it->volume_, data_it->key_pressed_,
  292. data_it->capture_time_);
  293. // Copy data from the fifo into shared memory using pre-allocated audio
  294. // buses.
  295. data_it->audio_bus_->CopyTo(audio_buses_[current_segment_id_].get());
  296. if (!SignalDataWrittenAndUpdateCounters())
  297. write_error = true;
  298. ++data_it;
  299. }
  300. // Erase all copied data from fifo.
  301. overflow_data_.erase(overflow_data_.begin(), data_it);
  302. if (overflow_data_.empty()) {
  303. static const char* message = "AISW: Fifo emptied.";
  304. log_callback_.Run(message);
  305. }
  306. return !write_error;
  307. }
  308. void InputSyncWriter::WriteParametersToCurrentSegment(
  309. double volume,
  310. bool key_pressed,
  311. base::TimeTicks capture_time) {
  312. TRACE_EVENT1("audio", "WriteParametersToCurrentSegment", "capture time (ms)",
  313. (capture_time - base::TimeTicks()).InMillisecondsF());
  314. uint8_t* ptr = static_cast<uint8_t*>(shared_memory_mapping_.memory());
  315. CHECK_LT(current_segment_id_, audio_buses_.size());
  316. ptr += current_segment_id_ * shared_memory_segment_size_;
  317. auto* buffer = reinterpret_cast<media::AudioInputBuffer*>(ptr);
  318. buffer->params.volume = volume;
  319. buffer->params.size = audio_bus_memory_size_;
  320. buffer->params.key_pressed = key_pressed;
  321. buffer->params.capture_time_us =
  322. (capture_time - base::TimeTicks()).InMicroseconds();
  323. buffer->params.id = next_buffer_id_;
  324. }
  325. bool InputSyncWriter::SignalDataWrittenAndUpdateCounters() {
  326. if (socket_->Send(&current_segment_id_, sizeof(current_segment_id_)) !=
  327. sizeof(current_segment_id_)) {
  328. // Ensure we don't log consecutive errors as this can lead to a large
  329. // amount of logs.
  330. if (!had_socket_error_) {
  331. had_socket_error_ = true;
  332. static const char* error_message = "AISW: No room in socket buffer.";
  333. PLOG(WARNING) << error_message;
  334. log_callback_.Run(error_message);
  335. TRACE_EVENT_INSTANT0("audio", "InputSyncWriter: No room in socket buffer",
  336. TRACE_EVENT_SCOPE_THREAD);
  337. }
  338. return false;
  339. } else {
  340. had_socket_error_ = false;
  341. }
  342. if (++current_segment_id_ >= audio_buses_.size())
  343. current_segment_id_ = 0;
  344. ++number_of_filled_segments_;
  345. CHECK_LE(number_of_filled_segments_, audio_buses_.size());
  346. ++next_buffer_id_;
  347. return true;
  348. }
  349. } // namespace audio