Refactored CL for moving the output to a separate thread.

webrtc/call/rtc_event_log_helper_thread.h

+/*
+ *  Copyright (c) 2016 The WebRTC project authors. All Rights Reserved.
+ *
+ *  Use of this source code is governed by a BSD-style license
+ *  that can be found in the LICENSE file in the root of the source
+ *  tree. An additional intellectual property rights grant can be found
+ *  in the file PATENTS.  All contributing project authors may
+ *  be found in the AUTHORS file in the root of the source tree.
+ */
+
+#ifndef WEBRTC_CALL_RTC_EVENT_LOG_HELPER_THREAD_H_
+#define WEBRTC_CALL_RTC_EVENT_LOG_HELPER_THREAD_H_
+
+#include <limits>
+#include <string>
+#include <utility>
+#include <vector>
+
+#include "webrtc/base/constructormagic.h"
+#include "webrtc/base/event.h"
+#include "webrtc/base/platform_thread.h"
+#include "webrtc/base/swap_queue.h"
+#include "webrtc/call/ringbuffer.h"
+#include "webrtc/system_wrappers/include/clock.h"
+#include "webrtc/system_wrappers/include/file_wrapper.h"
+
+#ifdef ENABLE_RTC_EVENT_LOG
+// Files generated at build-time by the protobuf compiler.
+#ifdef WEBRTC_ANDROID_PLATFORM_BUILD
+#include "external/webrtc/webrtc/call/rtc_event_log.pb.h"
+#else
+#include "webrtc/call/rtc_event_log.pb.h"
+#endif
+#endif
+
+#ifdef ENABLE_RTC_EVENT_LOG
+
+namespace webrtc {
+
+class RtcEventLogHelperThread {

[the sun, 2016/03/24 13:49:43]

final

[terelius, 2016/04/21 08:10:40]

Done.

+ public:
+  struct ControlMessage {
+    ControlMessage()
+        : message_type(STOP_FILE),
+          file(nullptr),
+          max_size_bytes(0),
+          start_time(0),
+          stop_time(0) {}
+    enum { START_FILE, STOP_FILE, TERMINATE_THREAD } message_type;
+
+    rtc::scoped_ptr<FileWrapper> file;  // Only used with START_FILE.

[the sun, 2016/03/24 13:49:43]

unique_ptr

[the sun, 2016/04/20 11:30:15]

Still want this.

[terelius, 2016/04/21 08:10:40]

Done.

+    int64_t max_size_bytes;             // Only used with START_FILE.
+    int64_t start_time;                 // Only used with START_FILE.
+    int64_t stop_time;                  // Used with all 3 message types.
+
+    friend void swap(ControlMessage& lhs, ControlMessage& rhs) {
+      using std::swap;
+      swap(lhs.message_type, rhs.message_type);
+      lhs.file.swap(rhs.file);
+      swap(lhs.max_size_bytes, rhs.max_size_bytes);
+      swap(lhs.start_time, rhs.start_time);
+      swap(lhs.stop_time, rhs.stop_time);
+    }
+  };
+
+  RtcEventLogHelperThread(SwapQueue<ControlMessage>* message_queue,
+                          SwapQueue<rtclog::Event>* config_queue,
+                          SwapQueue<rtclog::Event>* rtp_queue,
+                          SwapQueue<rtclog::Event>* rtcp_queue,
+                          SwapQueue<rtclog::Event>* acm_playout_queue,
+                          SwapQueue<rtclog::Event>* bwe_loss_queue,
+                          rtc::Event* wake_up,
+                          rtc::Event* file_finished,
+                          const Clock* const clock);
+  ~RtcEventLogHelperThread();
+
+ private:
+  static bool ThreadOutputFunction(void* obj);
+
+  void TerminateThread();
+  bool AppendEventToString(rtclog::Event* event);
+  void AppendEventToHistory(const rtclog::Event& event);
+  bool ProcessInOrder(bool memory, int64_t current_time);
+  void LogToMemory();
+  void StartLogFile();
+  void LogToFile();
+  void StopLogFile();
+  void WriteLog();
+
+  // Message queues for passing events to the logging thread.
+  SwapQueue<ControlMessage>* message_queue_;
+  SwapQueue<rtclog::Event>* config_queue_;
+  SwapQueue<rtclog::Event>* rtp_queue_;
+  SwapQueue<rtclog::Event>* rtcp_queue_;
+  SwapQueue<rtclog::Event>* acm_playout_queue_;
+  SwapQueue<rtclog::Event>* bwe_loss_queue_;
+
+  // History containing the most recent events (~ 10 s).
+  RingBuffer<rtclog::Event> history_;

[the sun, 2016/03/24 13:49:43]

I realize we've been at this before, but using a buffer of rtclog::Event:s for
the history feels wrong to me. I think either you're interested in keeping the
last N seconds of events (in which case you need to use a variable size queue
and look at time stamps), or you're interested in limiting the memory required
for the history (in which case you are best off serializing the messages as they
go into the history).

A buffer of a preset number of proto messages will achieve neither of the above.
When the distribution changes (e.g. new log points are added), you may either
start overusing memory, or keeping a too short history. The results aren't very
deterministic with the current solution.

The best option is likely to keep a buffer of serialized protos to limit the
runtime memory footprint. Incidentally that should make the code simpler too, as
there is less difference between logging to file/memory.

[terelius, 2016/03/29 09:38:32]

As discussed in a previous comment, I would like to keep a history of serialized
events. However, the natural way to do this (without keeping memory unused or
allocating new memory for each event) requires a custom ringbuffer where you can
request space for a certain number of bytes. While this isn't difficult, it is
more complicated than the current ring buffer so I figured it would be better to
not try cramming it into the same CL.

[the sun, 2016/03/30 09:12:39]

One custom ring buffer for another custom ring buffer? Hmm.

Well. *maybe* we have to land this anyway and go back and refine it. Stefan,
wdyt?

[stefan-webrtc, 2016/03/30 09:23:55]

I would very much prefer landing something sooner rather than later. Would it be
reasonable to go back and refine this when we have tried it out a bit and have a
better idea what we want to optimize for?

We don't know if there's a point in optimizing for even less memory usage, once
we decide it is we should write a short design doc of how to improve and agree
on the optimal solution. SG? :)

We'll continue working on this in Q2, but we really need something like this CL
sooner rather than later.

 

[terelius, 2016/03/30 10:36:59]

The point is that the ringbuffer for serialized events would be significantly
more complicated. You need to keep track of where each event start and end, and
you need to handle serialized events that wrap across the memory boundary. This
is not technically difficult, but will make the code more complex. To keep the
code as simple as possible (as you requested) I prefer to go for a solution that
improves both the usefulness of the log and the robustness to changes even
though the solution isn't optimal.

Compared to a time based window, the produced logs will be more useful since we
can keep more events in memory if we have space to spare, and it is more robust
since adding new small-ish event types or more log calls does not increase
memory usage.

[stefan-webrtc, 2016/04/01 13:46:25]

Sounds like a reasonable trade-off to me for the first version. I suggest we
move it in either direction once we know what we really want (reduce memory
footprint or a true time limit, or both).

Solis, let me know if you disagree.

+
+  // History containing all past configuration events.
+  std::vector<rtclog::Event> config_history_;
+
+  rtc::scoped_ptr<FileWrapper> file_;
+  rtc::PlatformThread thread_;
+
+  int64_t max_size_bytes_;
+  int64_t written_bytes_;
+  int64_t start_time_;
+  int64_t stop_time_;
+
+  // We want to extract the elements from the buffers in timestamp order
+  // and, because we can't peek into the SwapQueue, we need to keep the first
+  // elements outside.
+  rtclog::Event config_event_;
+  rtclog::Event rtp_event_;
+  rtclog::Event rtcp_event_;
+  rtclog::Event playout_event_;
+  rtclog::Event loss_event_;
+  bool valid_config_event_;
+  bool valid_rtp_event_;
+  bool valid_rtcp_event_;
+  bool valid_playout_event_;
+  bool valid_loss_event_;
+
+  // Temporary space for serializing profobuf data.
+  std::string output_string_;
+
+  rtc::Event* wake_up_;
+  rtc::Event* stopped_;
+
+  const Clock* const clock_;
+
+  RTC_DISALLOW_IMPLICIT_CONSTRUCTORS(RtcEventLogHelperThread);
+};
+
+}  // namespace webrtc
+
+#endif  // ENABLE_RTC_EVENT_LOG
+
+#endif  // WEBRTC_CALL_RTC_EVENT_LOG_HELPER_THREAD_H_