blob: 1e9a21801aaa1eb050e63c2fd8b88c45d27142a1 [file] [log] [blame]
Austin Schuhe309d2a2019-11-29 13:25:21 -08001#ifndef AOS_EVENTS_LOGGER_H_
2#define AOS_EVENTS_LOGGER_H_
3
4#include <deque>
5#include <vector>
6
7#include "absl/strings/string_view.h"
8#include "absl/types/span.h"
9#include "aos/events/event_loop.h"
James Kuszmaul38735e82019-12-07 16:42:06 -080010#include "aos/events/logging/logger_generated.h"
Austin Schuh92547522019-12-28 14:33:43 -080011#include "aos/events/simulated_event_loop.h"
Austin Schuhe309d2a2019-11-29 13:25:21 -080012#include "aos/time/time.h"
13#include "flatbuffers/flatbuffers.h"
14
15namespace aos {
16namespace logger {
17
18// This class manages efficiently writing a sequence of detached buffers to a
19// file. It queues them up and batches the write operation.
20class DetachedBufferWriter {
21 public:
22 DetachedBufferWriter(absl::string_view filename);
23 ~DetachedBufferWriter();
24
25 // TODO(austin): Snappy compress the log file if it ends with .snappy!
26
27 // Queues up a finished FlatBufferBuilder to be written. Steals the detached
28 // buffer from it.
29 void QueueSizedFlatbuffer(flatbuffers::FlatBufferBuilder *fbb);
30 // Queues up a detached buffer directly.
31 void QueueSizedFlatbuffer(flatbuffers::DetachedBuffer &&buffer);
32
33 // Triggers data to be provided to the kernel and written.
34 void Flush();
35
36 private:
37 int fd_ = -1;
38
39 // Size of all the data in the queue.
40 size_t queued_size_ = 0;
41
42 // List of buffers to flush.
43 std::vector<flatbuffers::DetachedBuffer> queue_;
44 // List of iovecs to use with writev. This is a member variable to avoid
45 // churn.
46 std::vector<struct iovec> iovec_;
47};
48
Austin Schuh15649d62019-12-28 16:36:38 -080049enum class LogType : uint8_t {
50 // The message originated on this node and should be logged here.
51 kLogMessage,
52 // The message originated on another node, but only the delivery times are
53 // logged here.
54 kLogDeliveryTimeOnly,
55 // The message originated on another node. Log it and the delivery times
56 // together. The message_gateway is responsible for logging any messages
57 // which didn't get delivered.
58 kLogMessageAndDeliveryTime
59};
Austin Schuh646b7b82019-12-22 21:38:55 -080060
Austin Schuhe309d2a2019-11-29 13:25:21 -080061// Logs all channels available in the event loop to disk every 100 ms.
62// Start by logging one message per channel to capture any state and
63// configuration that is sent rately on a channel and would affect execution.
64class Logger {
65 public:
66 Logger(DetachedBufferWriter *writer, EventLoop *event_loop,
67 std::chrono::milliseconds polling_period =
68 std::chrono::milliseconds(100));
69
70 private:
71 void DoLogData();
72
73 EventLoop *event_loop_;
74 DetachedBufferWriter *writer_;
75
76 // Structure to track both a fetcher, and if the data fetched has been
77 // written. We may want to delay writing data to disk so that we don't let
78 // data get too far out of order when written to disk so we can avoid making
79 // it too hard to sort when reading.
80 struct FetcherStruct {
81 std::unique_ptr<RawFetcher> fetcher;
82 bool written = false;
Austin Schuh15649d62019-12-28 16:36:38 -080083
84 LogType log_type;
Austin Schuhe309d2a2019-11-29 13:25:21 -080085 };
86
87 std::vector<FetcherStruct> fetchers_;
88 TimerHandler *timer_handler_;
89
90 // Period to poll the channels.
91 const std::chrono::milliseconds polling_period_;
92
93 // Last time that data was written for all channels to disk.
94 monotonic_clock::time_point last_synchronized_time_;
95
96 // Max size that the header has consumed. This much extra data will be
97 // reserved in the builder to avoid reallocating.
98 size_t max_header_size_ = 0;
99};
100
Austin Schuh15649d62019-12-28 16:36:38 -0800101// Packes a message pointed to by the context into a MessageHeader.
102flatbuffers::Offset<MessageHeader> PackMessage(
103 flatbuffers::FlatBufferBuilder *fbb, const Context &context,
104 int channel_index, LogType log_type);
105
Austin Schuhe309d2a2019-11-29 13:25:21 -0800106// Replays all the channels in the logfile to the event loop.
107class LogReader {
108 public:
109 LogReader(absl::string_view filename);
110
111 // Registers the timer and senders used to resend the messages from the log
112 // file.
113 void Register(EventLoop *event_loop);
Austin Schuh92547522019-12-28 14:33:43 -0800114 // Registers everything, but also updates the real time time in sync. Runs
115 // until the log file starts.
116 void Register(SimulatedEventLoopFactory *factory);
Austin Schuhe309d2a2019-11-29 13:25:21 -0800117 // Unregisters the senders.
118 void Deregister();
119
120 // TODO(austin): Remap channels?
121
122 // Returns the configuration from the log file.
Austin Schuh15649d62019-12-28 16:36:38 -0800123 const Configuration *configuration() const;
124
125 // Returns the node that this log file was created on.
126 const Node *node() const;
Austin Schuhe309d2a2019-11-29 13:25:21 -0800127
128 // Returns the starting timestamp for the log file.
129 monotonic_clock::time_point monotonic_start_time();
130 realtime_clock::time_point realtime_start_time();
131
132 // TODO(austin): Add the ability to re-publish the fetched messages. Add 2
133 // options, one which publishes them *now*, and another which publishes them
134 // to the simulated event loop factory back in time where they actually
135 // happened.
136
137 private:
138 // Reads a chunk of data into data_. Returns false if no data was read.
139 bool ReadBlock();
140
141 // Returns true if there is a full message available in the buffer, or if we
142 // will have to read more data from disk.
143 bool MessageAvailable();
144
Austin Schuh15649d62019-12-28 16:36:38 -0800145 // Returns a span with the data for a message from the log file, excluding
146 // the size.
Austin Schuhe309d2a2019-11-29 13:25:21 -0800147 absl::Span<const uint8_t> ReadMessage();
148
149 // Queues at least max_out_of_order_duration_ messages into channels_.
150 void QueueMessages();
151
152 // We need to read a large chunk at a time, then kit it up into parts and
153 // sort.
154 //
155 // We want to read 256 KB chunks at a time. This is the fastest read size.
156 // This leaves us with a fragmentation problem though.
157 //
158 // The easy answer is to read 256 KB chunks. Then, malloc and memcpy those
159 // chunks into single flatbuffer messages and manage them in a sorted queue.
160 // Everything is copied three times (into 256 kb buffer, then into separate
161 // buffer, then into sender), but none of it is all that expensive. We can
162 // optimize if it is slow later.
163 //
Austin Schuh15649d62019-12-28 16:36:38 -0800164 // As we place the elements in the sorted list of times, keep doing this
165 // until we read a message that is newer than the threshold.
Austin Schuhe309d2a2019-11-29 13:25:21 -0800166 //
167 // Then repeat. Keep filling up the sorted list with 256 KB chunks (need a
168 // small state machine so we can resume), and keep pulling messages back out
169 // and sending.
170 //
Austin Schuh15649d62019-12-28 16:36:38 -0800171 // For sorting, we want to use the fact that each channel is sorted, and
172 // then merge sort the channels. Have a vector of deques, and then hold a
173 // sorted list of pointers to those.
Austin Schuhe309d2a2019-11-29 13:25:21 -0800174 //
175 // TODO(austin): Multithreaded read at some point. Gotta go faster!
176 // Especially if we start compressing.
177
178 // Allocator which doesn't zero initialize memory.
179 template <typename T>
180 struct DefaultInitAllocator {
181 typedef T value_type;
182
183 template <typename U>
184 void construct(U *p) {
185 ::new (static_cast<void *>(p)) U;
186 }
187
188 template <typename U, typename... Args>
189 void construct(U *p, Args &&... args) {
190 ::new (static_cast<void *>(p)) U(std::forward<Args>(args)...);
191 }
192
193 T *allocate(std::size_t n) {
194 return reinterpret_cast<T *>(::operator new(sizeof(T) * n));
195 }
196
197 template <typename U>
198 void deallocate(U *p, std::size_t /*n*/) {
199 ::operator delete(static_cast<void *>(p));
200 }
201 };
202
Austin Schuh15649d62019-12-28 16:36:38 -0800203 // Minimum amount of data to queue up for sorting before we are guarenteed
204 // to not see data out of order.
Austin Schuhe309d2a2019-11-29 13:25:21 -0800205 std::chrono::nanoseconds max_out_of_order_duration_;
206
207 // File descriptor for the log file.
208 int fd_ = -1;
209
Austin Schuh92547522019-12-28 14:33:43 -0800210 SimulatedEventLoopFactory *event_loop_factory_ = nullptr;
211 std::unique_ptr<EventLoop> event_loop_unique_ptr_;
212 EventLoop *event_loop_ = nullptr;
Austin Schuhe309d2a2019-11-29 13:25:21 -0800213 TimerHandler *timer_handler_;
214
Austin Schuh15649d62019-12-28 16:36:38 -0800215 // Vector to read into. This uses an allocator which doesn't zero
216 // initialize the memory.
Austin Schuhe309d2a2019-11-29 13:25:21 -0800217 std::vector<uint8_t, DefaultInitAllocator<uint8_t>> data_;
218
219 // Amount of data consumed already in data_.
220 size_t consumed_data_ = 0;
221
222 // Vector holding the data for the configuration.
223 std::vector<uint8_t> configuration_;
224
225 // Moves the message to the correct channel queue.
226 void EmplaceDataBack(FlatbufferVector<MessageHeader> &&new_data);
227
228 // Pushes a pointer to the channel for the given timestamp to the sorted
229 // channel list.
230 void PushChannelHeap(monotonic_clock::time_point timestamp,
231 int channel_index);
232
233 // Returns a pointer to the channel with the oldest message in it, and the
234 // timestamp.
235 const std::pair<monotonic_clock::time_point, int> &oldest_message() const {
236 return channel_heap_.front();
237 }
238
239 // Pops a pointer to the channel with the oldest message in it, and the
240 // timestamp.
241 std::pair<monotonic_clock::time_point, int> PopOldestChannel();
242
Austin Schuh15649d62019-12-28 16:36:38 -0800243 // Datastructure to hold the list of messages, cached timestamp for the
244 // oldest message, and sender to send with.
Austin Schuhe309d2a2019-11-29 13:25:21 -0800245 struct ChannelData {
246 monotonic_clock::time_point oldest_timestamp = monotonic_clock::min_time;
247 std::deque<FlatbufferVector<MessageHeader>> data;
248 std::unique_ptr<RawSender> raw_sender;
249
250 // Returns the oldest message.
251 const FlatbufferVector<MessageHeader> &front() { return data.front(); }
252
253 // Returns the timestamp for the oldest message.
254 const monotonic_clock::time_point front_timestamp() {
255 return monotonic_clock::time_point(
256 std::chrono::nanoseconds(front().message().monotonic_sent_time()));
257 }
258 };
259
260 // List of channels and messages for them.
261 std::vector<ChannelData> channels_;
262
263 // Heap of channels so we can track which channel to send next.
264 std::vector<std::pair<monotonic_clock::time_point, int>> channel_heap_;
265
266 // Timestamp of the newest message in a channel queue.
267 monotonic_clock::time_point newest_timestamp_ = monotonic_clock::min_time;
268
269 // The time at which we need to read another chunk from the logfile.
270 monotonic_clock::time_point queue_data_time_ = monotonic_clock::min_time;
271
272 // Cached bit for if we have reached the end of the file. Otherwise we will
273 // hammer on the kernel asking for more data each time we send.
274 bool end_of_file_ = false;
275};
276
277} // namespace logger
278} // namespace aos
279
280#endif // AOS_EVENTS_LOGGER_H_