blob: 86d813f1b084323d3e434df8521cec83a0d21070 [file] [log] [blame]
Austin Schuhcb5601b2020-09-10 15:29:59 -07001#include "aos/events/logging/log_namer.h"
2
3#include <functional>
4#include <map>
5#include <memory>
6#include <string_view>
7#include <vector>
8
9#include "absl/strings/str_cat.h"
10#include "aos/events/logging/logfile_utils.h"
11#include "aos/events/logging/logger_generated.h"
Austin Schuh73340842021-07-30 22:32:06 -070012#include "aos/flatbuffer_merge.h"
Austin Schuh4385b142021-03-14 21:31:13 -070013#include "aos/uuid.h"
Austin Schuhcb5601b2020-09-10 15:29:59 -070014#include "flatbuffers/flatbuffers.h"
15#include "glog/logging.h"
16
Austin Schuh8bdfc492023-02-11 12:53:13 -080017DECLARE_int32(flush_size);
18
Austin Schuhcb5601b2020-09-10 15:29:59 -070019namespace aos {
20namespace logger {
21
Austin Schuh572924a2021-07-30 22:32:12 -070022NewDataWriter::NewDataWriter(LogNamer *log_namer, const Node *node,
Austin Schuhf5f99f32022-02-07 20:05:37 -080023 const Node *logger_node,
Austin Schuh572924a2021-07-30 22:32:12 -070024 std::function<void(NewDataWriter *)> reopen,
Austin Schuh48d10d62022-10-16 22:19:23 -070025 std::function<void(NewDataWriter *)> close,
26 size_t max_message_size)
Austin Schuh572924a2021-07-30 22:32:12 -070027 : node_(node),
28 node_index_(configuration::GetNodeIndex(log_namer->configuration_, node)),
Austin Schuhf5f99f32022-02-07 20:05:37 -080029 logger_node_index_(
30 configuration::GetNodeIndex(log_namer->configuration_, logger_node)),
Austin Schuh572924a2021-07-30 22:32:12 -070031 log_namer_(log_namer),
32 reopen_(std::move(reopen)),
Austin Schuh48d10d62022-10-16 22:19:23 -070033 close_(std::move(close)),
34 max_message_size_(max_message_size) {
Austin Schuh72211ae2021-08-05 14:02:30 -070035 state_.resize(configuration::NodesCount(log_namer->configuration_));
36 CHECK_LT(node_index_, state_.size());
Austin Schuh572924a2021-07-30 22:32:12 -070037}
38
39NewDataWriter::~NewDataWriter() {
40 if (writer) {
41 Close();
42 }
43}
44
45void NewDataWriter::Rotate() {
Austin Schuhe46492f2021-07-31 19:49:41 -070046 // No need to rotate if nothing has been written.
47 if (header_written_) {
Austin Schuh58646e22021-08-23 23:51:46 -070048 VLOG(1) << "Rotated " << filename();
Austin Schuhe46492f2021-07-31 19:49:41 -070049 ++parts_index_;
50 reopen_(this);
51 header_written_ = false;
52 QueueHeader(MakeHeader());
53 }
Austin Schuh572924a2021-07-30 22:32:12 -070054}
55
Austin Schuh5e14d842022-01-21 12:02:15 -080056void NewDataWriter::Reboot(const UUID &source_node_boot_uuid) {
Austin Schuh572924a2021-07-30 22:32:12 -070057 parts_uuid_ = UUID::Random();
58 ++parts_index_;
59 reopen_(this);
60 header_written_ = false;
Austin Schuh5e14d842022-01-21 12:02:15 -080061 for (State &state : state_) {
62 state.boot_uuid = UUID::Zero();
63 state.oldest_remote_monotonic_timestamp = monotonic_clock::max_time;
64 state.oldest_local_monotonic_timestamp = monotonic_clock::max_time;
65 state.oldest_remote_unreliable_monotonic_timestamp =
66 monotonic_clock::max_time;
67 state.oldest_local_unreliable_monotonic_timestamp =
68 monotonic_clock::max_time;
Austin Schuhbfe6c572022-01-27 20:48:20 -080069 state.oldest_remote_reliable_monotonic_timestamp =
70 monotonic_clock::max_time;
Austin Schuhf5f99f32022-02-07 20:05:37 -080071 state.oldest_local_reliable_monotonic_timestamp = monotonic_clock::max_time;
72 state.oldest_logger_remote_unreliable_monotonic_timestamp =
73 monotonic_clock::max_time;
74 state.oldest_logger_local_unreliable_monotonic_timestamp =
Austin Schuhbfe6c572022-01-27 20:48:20 -080075 monotonic_clock::max_time;
Austin Schuh5e14d842022-01-21 12:02:15 -080076 }
77
78 state_[node_index_].boot_uuid = source_node_boot_uuid;
79
80 VLOG(1) << "Rebooted " << filename();
81}
82
83void NewDataWriter::UpdateBoot(const UUID &source_node_boot_uuid) {
84 if (state_[node_index_].boot_uuid != source_node_boot_uuid) {
85 state_[node_index_].boot_uuid = source_node_boot_uuid;
86 if (header_written_) {
87 Reboot(source_node_boot_uuid);
88 }
89 }
Austin Schuh572924a2021-07-30 22:32:12 -070090}
91
Austin Schuh72211ae2021-08-05 14:02:30 -070092void NewDataWriter::UpdateRemote(
93 const size_t remote_node_index, const UUID &remote_node_boot_uuid,
94 const monotonic_clock::time_point monotonic_remote_time,
Austin Schuhf5f99f32022-02-07 20:05:37 -080095 const monotonic_clock::time_point monotonic_event_time, const bool reliable,
96 monotonic_clock::time_point monotonic_timestamp_time) {
Austin Schuh58646e22021-08-23 23:51:46 -070097 // Trigger rotation if anything in the header changes.
Austin Schuh72211ae2021-08-05 14:02:30 -070098 bool rotate = false;
99 CHECK_LT(remote_node_index, state_.size());
100 State &state = state_[remote_node_index];
Austin Schuh58646e22021-08-23 23:51:46 -0700101
102 // Did the remote boot UUID change?
Austin Schuh72211ae2021-08-05 14:02:30 -0700103 if (state.boot_uuid != remote_node_boot_uuid) {
Austin Schuhe46492f2021-07-31 19:49:41 -0700104 VLOG(1) << filename() << " Remote " << remote_node_index << " updated to "
Austin Schuh72211ae2021-08-05 14:02:30 -0700105 << remote_node_boot_uuid << " from " << state.boot_uuid;
106 state.boot_uuid = remote_node_boot_uuid;
107 state.oldest_remote_monotonic_timestamp = monotonic_clock::max_time;
108 state.oldest_local_monotonic_timestamp = monotonic_clock::max_time;
109 state.oldest_remote_unreliable_monotonic_timestamp =
110 monotonic_clock::max_time;
111 state.oldest_local_unreliable_monotonic_timestamp =
112 monotonic_clock::max_time;
Austin Schuhbfe6c572022-01-27 20:48:20 -0800113 state.oldest_remote_reliable_monotonic_timestamp =
114 monotonic_clock::max_time;
Austin Schuhf5f99f32022-02-07 20:05:37 -0800115 state.oldest_local_reliable_monotonic_timestamp = monotonic_clock::max_time;
116 state.oldest_logger_remote_unreliable_monotonic_timestamp =
117 monotonic_clock::max_time;
118 state.oldest_logger_local_unreliable_monotonic_timestamp =
Austin Schuhbfe6c572022-01-27 20:48:20 -0800119 monotonic_clock::max_time;
Austin Schuh72211ae2021-08-05 14:02:30 -0700120 rotate = true;
121 }
122
Austin Schuh58646e22021-08-23 23:51:46 -0700123 // Did the unreliable timestamps change?
Austin Schuh72211ae2021-08-05 14:02:30 -0700124 if (!reliable) {
125 if (state.oldest_remote_unreliable_monotonic_timestamp >
126 monotonic_remote_time) {
Austin Schuh58646e22021-08-23 23:51:46 -0700127 VLOG(1) << filename() << " Remote " << remote_node_index
128 << " oldest_remote_unreliable_monotonic_timestamp updated from "
129 << state.oldest_remote_unreliable_monotonic_timestamp << " to "
130 << monotonic_remote_time;
Austin Schuh72211ae2021-08-05 14:02:30 -0700131 state.oldest_remote_unreliable_monotonic_timestamp =
132 monotonic_remote_time;
133 state.oldest_local_unreliable_monotonic_timestamp = monotonic_event_time;
134 rotate = true;
135 }
Austin Schuhbfe6c572022-01-27 20:48:20 -0800136 } else {
137 if (state.oldest_remote_reliable_monotonic_timestamp >
138 monotonic_remote_time) {
139 VLOG(1) << filename() << " Remote " << remote_node_index
140 << " oldest_remote_reliable_monotonic_timestamp updated from "
141 << state.oldest_remote_reliable_monotonic_timestamp << " to "
142 << monotonic_remote_time;
143 state.oldest_remote_reliable_monotonic_timestamp = monotonic_remote_time;
144 state.oldest_local_reliable_monotonic_timestamp = monotonic_event_time;
145 rotate = true;
146 }
Austin Schuh72211ae2021-08-05 14:02:30 -0700147 }
148
Austin Schuhf5f99f32022-02-07 20:05:37 -0800149 // Track the logger timestamps too.
150 if (monotonic_timestamp_time != monotonic_clock::min_time) {
151 State &logger_state = state_[node_index_];
152 CHECK_EQ(remote_node_index, logger_node_index_);
153 if (monotonic_event_time <
154 logger_state.oldest_logger_remote_unreliable_monotonic_timestamp) {
155 VLOG(1)
156 << filename() << " Remote " << node_index_
157 << " oldest_logger_remote_unreliable_monotonic_timestamp updated "
158 "from "
159 << logger_state.oldest_logger_remote_unreliable_monotonic_timestamp
160 << " to " << monotonic_event_time;
161 logger_state.oldest_logger_remote_unreliable_monotonic_timestamp =
162 monotonic_event_time;
163 logger_state.oldest_logger_local_unreliable_monotonic_timestamp =
164 monotonic_timestamp_time;
165
166 rotate = true;
167 }
168 }
169
Austin Schuh58646e22021-08-23 23:51:46 -0700170 // Did any of the timestamps change?
Austin Schuh72211ae2021-08-05 14:02:30 -0700171 if (state.oldest_remote_monotonic_timestamp > monotonic_remote_time) {
Austin Schuh58646e22021-08-23 23:51:46 -0700172 VLOG(1) << filename() << " Remote " << remote_node_index
173 << " oldest_remote_monotonic_timestamp updated from "
174 << state.oldest_remote_monotonic_timestamp << " to "
175 << monotonic_remote_time;
Austin Schuh72211ae2021-08-05 14:02:30 -0700176 state.oldest_remote_monotonic_timestamp = monotonic_remote_time;
177 state.oldest_local_monotonic_timestamp = monotonic_event_time;
178 rotate = true;
179 }
180
181 if (rotate) {
Austin Schuhe46492f2021-07-31 19:49:41 -0700182 Rotate();
183 }
184}
185
Austin Schuh48d10d62022-10-16 22:19:23 -0700186void NewDataWriter::CopyMessage(DataEncoder::Copier *coppier,
187 const UUID &source_node_boot_uuid,
188 aos::monotonic_clock::time_point now) {
Austin Schuh58646e22021-08-23 23:51:46 -0700189 // Trigger a reboot if we detect the boot UUID change.
Austin Schuh5e14d842022-01-21 12:02:15 -0800190 UpdateBoot(source_node_boot_uuid);
Austin Schuh572924a2021-07-30 22:32:12 -0700191
Austin Schuh5e14d842022-01-21 12:02:15 -0800192 if (!header_written_) {
Austin Schuhe46492f2021-07-31 19:49:41 -0700193 QueueHeader(MakeHeader());
Austin Schuh572924a2021-07-30 22:32:12 -0700194 }
Austin Schuh58646e22021-08-23 23:51:46 -0700195
196 // If the start time has changed for this node, trigger a rotation.
197 if (log_namer_->monotonic_start_time(node_index_, source_node_boot_uuid) !=
Austin Schuh5e14d842022-01-21 12:02:15 -0800198 monotonic_start_time_) {
Austin Schuh58646e22021-08-23 23:51:46 -0700199 CHECK(header_written_);
200 Rotate();
201 }
202
203 CHECK_EQ(log_namer_->monotonic_start_time(node_index_, source_node_boot_uuid),
204 monotonic_start_time_);
Austin Schuh72211ae2021-08-05 14:02:30 -0700205 CHECK_EQ(state_[node_index_].boot_uuid, source_node_boot_uuid);
milind-ua50344f2021-08-25 18:22:20 -0700206 CHECK(writer);
Austin Schuh572924a2021-07-30 22:32:12 -0700207 CHECK(header_written_) << ": Attempting to write message before header to "
208 << writer->filename();
Austin Schuh48d10d62022-10-16 22:19:23 -0700209 writer->CopyMessage(coppier, now);
Austin Schuh572924a2021-07-30 22:32:12 -0700210}
211
Austin Schuhe46492f2021-07-31 19:49:41 -0700212aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader>
213NewDataWriter::MakeHeader() {
214 const size_t logger_node_index = log_namer_->logger_node_index();
215 const UUID &logger_node_boot_uuid = log_namer_->logger_node_boot_uuid();
Austin Schuh72211ae2021-08-05 14:02:30 -0700216 if (state_[logger_node_index].boot_uuid == UUID::Zero()) {
Austin Schuhe46492f2021-07-31 19:49:41 -0700217 VLOG(1) << filename() << " Logger node is " << logger_node_index
218 << " and uuid is " << logger_node_boot_uuid;
Austin Schuh72211ae2021-08-05 14:02:30 -0700219 state_[logger_node_index].boot_uuid = logger_node_boot_uuid;
Austin Schuhe46492f2021-07-31 19:49:41 -0700220 } else {
Austin Schuh72211ae2021-08-05 14:02:30 -0700221 CHECK_EQ(state_[logger_node_index].boot_uuid, logger_node_boot_uuid);
Austin Schuhe46492f2021-07-31 19:49:41 -0700222 }
Austin Schuh72211ae2021-08-05 14:02:30 -0700223 return log_namer_->MakeHeader(node_index_, state_, parts_uuid(),
Austin Schuhe46492f2021-07-31 19:49:41 -0700224 parts_index_);
225}
226
Austin Schuh572924a2021-07-30 22:32:12 -0700227void NewDataWriter::QueueHeader(
228 aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> &&header) {
229 CHECK(!header_written_) << ": Attempting to write duplicate header to "
230 << writer->filename();
231 CHECK(header.message().has_source_node_boot_uuid());
Austin Schuh72211ae2021-08-05 14:02:30 -0700232 CHECK_EQ(state_[node_index_].boot_uuid,
Austin Schuhe46492f2021-07-31 19:49:41 -0700233 UUID::FromString(header.message().source_node_boot_uuid()));
Austin Schuh510dc622021-08-06 18:47:30 -0700234 if (!writer) {
Austin Schuh48d10d62022-10-16 22:19:23 -0700235 // Since we haven't opened the first time, it's still not too late to update
236 // the max message size. Make sure the header fits.
237 //
238 // This won't work well on reboots, but the structure of the header is fixed
239 // by that point in time, so it's size is fixed too.
240 //
241 // Most of the time, the minimum buffer size inside the encoder of around
242 // 128k will make this a non-issue.
243 UpdateMaxMessageSize(header.span().size());
244
Austin Schuh510dc622021-08-06 18:47:30 -0700245 reopen_(this);
246 }
247
Austin Schuh58646e22021-08-23 23:51:46 -0700248 VLOG(1) << "Writing to " << filename() << " "
249 << aos::FlatbufferToJson(
250 header, {.multi_line = false, .max_vector_size = 100});
251
Austin Schuh510dc622021-08-06 18:47:30 -0700252 CHECK(writer);
Austin Schuh7ef11a42023-02-04 17:15:12 -0800253 DataEncoder::SpanCopier coppier(header.span());
254 writer->CopyMessage(&coppier, aos::monotonic_clock::now());
Austin Schuh572924a2021-07-30 22:32:12 -0700255 header_written_ = true;
Austin Schuh58646e22021-08-23 23:51:46 -0700256 monotonic_start_time_ = log_namer_->monotonic_start_time(
257 node_index_, state_[node_index_].boot_uuid);
Austin Schuh572924a2021-07-30 22:32:12 -0700258}
259
260void NewDataWriter::Close() {
261 CHECK(writer);
262 close_(this);
263 writer.reset();
264 header_written_ = false;
265}
266
Austin Schuh58646e22021-08-23 23:51:46 -0700267LogNamer::NodeState *LogNamer::GetNodeState(size_t node_index,
268 const UUID &boot_uuid) {
269 auto it = node_states_.find(std::make_pair(node_index, boot_uuid));
270 if (it == node_states_.end()) {
271 it =
272 node_states_.emplace(std::make_pair(node_index, boot_uuid), NodeState())
273 .first;
274 }
275 return &it->second;
276}
277
Austin Schuh73340842021-07-30 22:32:06 -0700278aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> LogNamer::MakeHeader(
Austin Schuh72211ae2021-08-05 14:02:30 -0700279 size_t node_index, const std::vector<NewDataWriter::State> &state,
Austin Schuh58646e22021-08-23 23:51:46 -0700280 const UUID &parts_uuid, int parts_index) {
Austin Schuh72211ae2021-08-05 14:02:30 -0700281 const UUID &source_node_boot_uuid = state[node_index].boot_uuid;
Austin Schuh73340842021-07-30 22:32:06 -0700282 const Node *const source_node =
283 configuration::GetNode(configuration_, node_index);
Austin Schuhfa712682022-05-11 16:43:42 -0700284 CHECK_EQ(LogFileHeader::MiniReflectTypeTable()->num_elems, 34u);
Austin Schuh73340842021-07-30 22:32:06 -0700285 flatbuffers::FlatBufferBuilder fbb;
286 fbb.ForceDefaults(true);
287
288 flatbuffers::Offset<flatbuffers::String> config_sha256_offset;
289 flatbuffers::Offset<aos::Configuration> configuration_offset;
290 if (header_.message().has_configuration()) {
291 CHECK(!header_.message().has_configuration_sha256());
292 configuration_offset =
293 CopyFlatBuffer(header_.message().configuration(), &fbb);
294 } else {
295 CHECK(!header_.message().has_configuration());
296 CHECK(header_.message().has_configuration_sha256());
297 config_sha256_offset = fbb.CreateString(
298 header_.message().configuration_sha256()->string_view());
299 }
300
301 CHECK(header_.message().has_name());
302 const flatbuffers::Offset<flatbuffers::String> name_offset =
303 fbb.CreateString(header_.message().name()->string_view());
Austin Schuhfa712682022-05-11 16:43:42 -0700304 const flatbuffers::Offset<flatbuffers::String> logger_sha1_offset =
305 header_.message().has_logger_sha1()
306 ? fbb.CreateString(header_.message().logger_sha1()->string_view())
307 : 0;
308 const flatbuffers::Offset<flatbuffers::String> logger_version_offset =
309 header_.message().has_logger_version()
310 ? fbb.CreateString(header_.message().logger_version()->string_view())
311 : 0;
Austin Schuh73340842021-07-30 22:32:06 -0700312
313 CHECK(header_.message().has_log_event_uuid());
314 const flatbuffers::Offset<flatbuffers::String> log_event_uuid_offset =
315 fbb.CreateString(header_.message().log_event_uuid()->string_view());
316
317 CHECK(header_.message().has_logger_instance_uuid());
318 const flatbuffers::Offset<flatbuffers::String> logger_instance_uuid_offset =
319 fbb.CreateString(header_.message().logger_instance_uuid()->string_view());
320
321 flatbuffers::Offset<flatbuffers::String> log_start_uuid_offset;
322 if (header_.message().has_log_start_uuid()) {
323 log_start_uuid_offset =
324 fbb.CreateString(header_.message().log_start_uuid()->string_view());
325 }
326
327 CHECK(header_.message().has_logger_node_boot_uuid());
328 const flatbuffers::Offset<flatbuffers::String> logger_node_boot_uuid_offset =
329 fbb.CreateString(
330 header_.message().logger_node_boot_uuid()->string_view());
331
332 CHECK_NE(source_node_boot_uuid, UUID::Zero());
333 const flatbuffers::Offset<flatbuffers::String> source_node_boot_uuid_offset =
334 source_node_boot_uuid.PackString(&fbb);
335
336 const flatbuffers::Offset<flatbuffers::String> parts_uuid_offset =
337 parts_uuid.PackString(&fbb);
338
339 flatbuffers::Offset<Node> node_offset;
340 flatbuffers::Offset<Node> logger_node_offset;
341
342 if (configuration::MultiNode(configuration_)) {
343 node_offset = RecursiveCopyFlatBuffer(source_node, &fbb);
344 logger_node_offset = RecursiveCopyFlatBuffer(node_, &fbb);
345 }
346
Austin Schuhe46492f2021-07-31 19:49:41 -0700347 std::vector<flatbuffers::Offset<flatbuffers::String>> boot_uuid_offsets;
Austin Schuh72211ae2021-08-05 14:02:30 -0700348 boot_uuid_offsets.reserve(state.size());
Austin Schuhe46492f2021-07-31 19:49:41 -0700349
Austin Schuh4db9ec92021-09-22 13:11:12 -0700350 int64_t *unused;
Austin Schuh72211ae2021-08-05 14:02:30 -0700351 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
Austin Schuhf5f99f32022-02-07 20:05:37 -0800352 oldest_remote_monotonic_timestamps_offset =
353 fbb.CreateUninitializedVector(state.size(), &unused);
Austin Schuh72211ae2021-08-05 14:02:30 -0700354
Austin Schuh72211ae2021-08-05 14:02:30 -0700355 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
Austin Schuhf5f99f32022-02-07 20:05:37 -0800356 oldest_local_monotonic_timestamps_offset =
357 fbb.CreateUninitializedVector(state.size(), &unused);
Austin Schuh72211ae2021-08-05 14:02:30 -0700358
Austin Schuh72211ae2021-08-05 14:02:30 -0700359 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
360 oldest_remote_unreliable_monotonic_timestamps_offset =
Austin Schuhf5f99f32022-02-07 20:05:37 -0800361 fbb.CreateUninitializedVector(state.size(), &unused);
Austin Schuh72211ae2021-08-05 14:02:30 -0700362
Austin Schuh72211ae2021-08-05 14:02:30 -0700363 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
364 oldest_local_unreliable_monotonic_timestamps_offset =
Austin Schuhf5f99f32022-02-07 20:05:37 -0800365 fbb.CreateUninitializedVector(state.size(), &unused);
Austin Schuh72211ae2021-08-05 14:02:30 -0700366
Austin Schuhbfe6c572022-01-27 20:48:20 -0800367 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
368 oldest_remote_reliable_monotonic_timestamps_offset =
Austin Schuhf5f99f32022-02-07 20:05:37 -0800369 fbb.CreateUninitializedVector(state.size(), &unused);
Austin Schuhbfe6c572022-01-27 20:48:20 -0800370
371 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
372 oldest_local_reliable_monotonic_timestamps_offset =
Austin Schuhf5f99f32022-02-07 20:05:37 -0800373 fbb.CreateUninitializedVector(state.size(), &unused);
374
375 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
376 oldest_logger_remote_unreliable_monotonic_timestamps_offset =
377 fbb.CreateUninitializedVector(state.size(), &unused);
378
379 flatbuffers::Offset<flatbuffers::Vector<int64_t>>
380 oldest_logger_local_unreliable_monotonic_timestamps_offset =
381 fbb.CreateUninitializedVector(state.size(), &unused);
Austin Schuhbfe6c572022-01-27 20:48:20 -0800382
Austin Schuh72211ae2021-08-05 14:02:30 -0700383 for (size_t i = 0; i < state.size(); ++i) {
Austin Schuh4db9ec92021-09-22 13:11:12 -0700384 if (state[i].boot_uuid != UUID::Zero()) {
385 boot_uuid_offsets.emplace_back(state[i].boot_uuid.PackString(&fbb));
386 } else {
387 boot_uuid_offsets.emplace_back(fbb.CreateString(""));
388 }
Austin Schuh5ae8f4a2021-09-11 19:09:50 -0700389 if (state[i].boot_uuid == UUID::Zero()) {
390 CHECK_EQ(state[i].oldest_remote_monotonic_timestamp,
391 monotonic_clock::max_time);
392 CHECK_EQ(state[i].oldest_local_monotonic_timestamp,
393 monotonic_clock::max_time);
394 CHECK_EQ(state[i].oldest_remote_unreliable_monotonic_timestamp,
395 monotonic_clock::max_time);
396 CHECK_EQ(state[i].oldest_local_unreliable_monotonic_timestamp,
397 monotonic_clock::max_time);
Austin Schuhbfe6c572022-01-27 20:48:20 -0800398 CHECK_EQ(state[i].oldest_remote_reliable_monotonic_timestamp,
399 monotonic_clock::max_time);
400 CHECK_EQ(state[i].oldest_local_reliable_monotonic_timestamp,
401 monotonic_clock::max_time);
Austin Schuhf5f99f32022-02-07 20:05:37 -0800402 CHECK_EQ(state[i].oldest_logger_remote_unreliable_monotonic_timestamp,
403 monotonic_clock::max_time);
404 CHECK_EQ(state[i].oldest_logger_local_unreliable_monotonic_timestamp,
405 monotonic_clock::max_time);
Austin Schuh5ae8f4a2021-09-11 19:09:50 -0700406 }
407
Austin Schuh4db9ec92021-09-22 13:11:12 -0700408 flatbuffers::GetMutableTemporaryPointer(
409 fbb, oldest_remote_monotonic_timestamps_offset)
410 ->Mutate(i, state[i]
411 .oldest_remote_monotonic_timestamp.time_since_epoch()
412 .count());
413 flatbuffers::GetMutableTemporaryPointer(
414 fbb, oldest_local_monotonic_timestamps_offset)
415 ->Mutate(i, state[i]
416 .oldest_local_monotonic_timestamp.time_since_epoch()
417 .count());
418 flatbuffers::GetMutableTemporaryPointer(
419 fbb, oldest_remote_unreliable_monotonic_timestamps_offset)
420 ->Mutate(i, state[i]
Austin Schuhbfe6c572022-01-27 20:48:20 -0800421 .oldest_remote_unreliable_monotonic_timestamp
422 .time_since_epoch()
Austin Schuh4db9ec92021-09-22 13:11:12 -0700423 .count());
424 flatbuffers::GetMutableTemporaryPointer(
425 fbb, oldest_local_unreliable_monotonic_timestamps_offset)
426 ->Mutate(i, state[i]
Austin Schuhbfe6c572022-01-27 20:48:20 -0800427 .oldest_local_unreliable_monotonic_timestamp
428 .time_since_epoch()
Austin Schuh4db9ec92021-09-22 13:11:12 -0700429 .count());
Austin Schuhbfe6c572022-01-27 20:48:20 -0800430
431 flatbuffers::GetMutableTemporaryPointer(
432 fbb, oldest_remote_reliable_monotonic_timestamps_offset)
433 ->Mutate(i, state[i]
434 .oldest_remote_reliable_monotonic_timestamp
435 .time_since_epoch()
436 .count());
437 flatbuffers::GetMutableTemporaryPointer(
438 fbb, oldest_local_reliable_monotonic_timestamps_offset)
439 ->Mutate(
440 i, state[i]
441 .oldest_local_reliable_monotonic_timestamp.time_since_epoch()
442 .count());
Austin Schuhf5f99f32022-02-07 20:05:37 -0800443
444 flatbuffers::GetMutableTemporaryPointer(
445 fbb, oldest_logger_remote_unreliable_monotonic_timestamps_offset)
446 ->Mutate(i, state[i]
447 .oldest_logger_remote_unreliable_monotonic_timestamp
448 .time_since_epoch()
449 .count());
450 flatbuffers::GetMutableTemporaryPointer(
451 fbb, oldest_logger_local_unreliable_monotonic_timestamps_offset)
452 ->Mutate(i, state[i]
453 .oldest_logger_local_unreliable_monotonic_timestamp
454 .time_since_epoch()
455 .count());
Austin Schuh72211ae2021-08-05 14:02:30 -0700456 }
457
Austin Schuh4db9ec92021-09-22 13:11:12 -0700458 flatbuffers::Offset<
459 flatbuffers::Vector<flatbuffers::Offset<flatbuffers::String>>>
460 boot_uuids_offset = fbb.CreateVector(boot_uuid_offsets);
461
Austin Schuh73340842021-07-30 22:32:06 -0700462 aos::logger::LogFileHeader::Builder log_file_header_builder(fbb);
463
464 log_file_header_builder.add_name(name_offset);
Austin Schuhfa712682022-05-11 16:43:42 -0700465 if (!logger_sha1_offset.IsNull()) {
466 log_file_header_builder.add_logger_sha1(logger_sha1_offset);
467 }
468 if (!logger_version_offset.IsNull()) {
469 log_file_header_builder.add_logger_version(logger_version_offset);
470 }
Austin Schuh73340842021-07-30 22:32:06 -0700471
472 // Only add the node if we are running in a multinode configuration.
473 if (!logger_node_offset.IsNull()) {
474 log_file_header_builder.add_node(node_offset);
475 log_file_header_builder.add_logger_node(logger_node_offset);
476 }
477
478 if (!configuration_offset.IsNull()) {
479 log_file_header_builder.add_configuration(configuration_offset);
480 }
481 log_file_header_builder.add_max_out_of_order_duration(
482 header_.message().max_out_of_order_duration());
483
Austin Schuh58646e22021-08-23 23:51:46 -0700484 NodeState *node_state = GetNodeState(node_index, source_node_boot_uuid);
Austin Schuh73340842021-07-30 22:32:06 -0700485 log_file_header_builder.add_monotonic_start_time(
486 std::chrono::duration_cast<std::chrono::nanoseconds>(
Austin Schuh58646e22021-08-23 23:51:46 -0700487 node_state->monotonic_start_time.time_since_epoch())
Austin Schuh73340842021-07-30 22:32:06 -0700488 .count());
489 if (source_node == node_) {
490 log_file_header_builder.add_realtime_start_time(
491 std::chrono::duration_cast<std::chrono::nanoseconds>(
Austin Schuh58646e22021-08-23 23:51:46 -0700492 node_state->realtime_start_time.time_since_epoch())
Austin Schuh73340842021-07-30 22:32:06 -0700493 .count());
494 } else {
495 // Fill out the legacy start times. Since these were implemented to never
496 // change on reboot, they aren't very helpful in tracking what happened.
497 log_file_header_builder.add_logger_monotonic_start_time(
498 std::chrono::duration_cast<std::chrono::nanoseconds>(
Austin Schuh58646e22021-08-23 23:51:46 -0700499 node_state->logger_monotonic_start_time.time_since_epoch())
Austin Schuh73340842021-07-30 22:32:06 -0700500 .count());
501 log_file_header_builder.add_logger_realtime_start_time(
502 std::chrono::duration_cast<std::chrono::nanoseconds>(
Austin Schuh58646e22021-08-23 23:51:46 -0700503 node_state->logger_realtime_start_time.time_since_epoch())
Austin Schuh73340842021-07-30 22:32:06 -0700504 .count());
505 }
506
507 // TODO(austin): Add more useful times. When was this part started? What do
508 // we know about both the logger and remote then?
509
510 log_file_header_builder.add_log_event_uuid(log_event_uuid_offset);
511 log_file_header_builder.add_logger_instance_uuid(logger_instance_uuid_offset);
512 if (!log_start_uuid_offset.IsNull()) {
513 log_file_header_builder.add_log_start_uuid(log_start_uuid_offset);
514 }
515 log_file_header_builder.add_logger_node_boot_uuid(
516 logger_node_boot_uuid_offset);
517 log_file_header_builder.add_source_node_boot_uuid(
518 source_node_boot_uuid_offset);
519
520 log_file_header_builder.add_parts_uuid(parts_uuid_offset);
521 log_file_header_builder.add_parts_index(parts_index);
522
523 if (!config_sha256_offset.IsNull()) {
524 log_file_header_builder.add_configuration_sha256(config_sha256_offset);
525 }
526
Austin Schuhe46492f2021-07-31 19:49:41 -0700527 log_file_header_builder.add_boot_uuids(boot_uuids_offset);
Austin Schuha499cea2021-07-31 19:49:53 -0700528 log_file_header_builder.add_logger_part_monotonic_start_time(
529 std::chrono::duration_cast<std::chrono::nanoseconds>(
530 event_loop_->monotonic_now().time_since_epoch())
531 .count());
532 log_file_header_builder.add_logger_part_realtime_start_time(
533 std::chrono::duration_cast<std::chrono::nanoseconds>(
534 event_loop_->realtime_now().time_since_epoch())
535 .count());
Austin Schuh72211ae2021-08-05 14:02:30 -0700536 log_file_header_builder.add_oldest_remote_monotonic_timestamps(
537 oldest_remote_monotonic_timestamps_offset);
538 log_file_header_builder.add_oldest_local_monotonic_timestamps(
539 oldest_local_monotonic_timestamps_offset);
540 log_file_header_builder.add_oldest_remote_unreliable_monotonic_timestamps(
541 oldest_remote_unreliable_monotonic_timestamps_offset);
542 log_file_header_builder.add_oldest_local_unreliable_monotonic_timestamps(
543 oldest_local_unreliable_monotonic_timestamps_offset);
Austin Schuhbfe6c572022-01-27 20:48:20 -0800544 log_file_header_builder.add_oldest_remote_reliable_monotonic_timestamps(
545 oldest_remote_reliable_monotonic_timestamps_offset);
546 log_file_header_builder.add_oldest_local_reliable_monotonic_timestamps(
547 oldest_local_reliable_monotonic_timestamps_offset);
Austin Schuhf5f99f32022-02-07 20:05:37 -0800548 log_file_header_builder
549 .add_oldest_logger_remote_unreliable_monotonic_timestamps(
550 oldest_logger_remote_unreliable_monotonic_timestamps_offset);
551 log_file_header_builder
552 .add_oldest_logger_local_unreliable_monotonic_timestamps(
553 oldest_logger_local_unreliable_monotonic_timestamps_offset);
Austin Schuh73340842021-07-30 22:32:06 -0700554 fbb.FinishSizePrefixed(log_file_header_builder.Finish());
555 aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> result(
556 fbb.Release());
557
558 CHECK(result.Verify()) << ": Built a corrupted header.";
559
560 return result;
Austin Schuhcb5601b2020-09-10 15:29:59 -0700561}
562
Austin Schuhcb5601b2020-09-10 15:29:59 -0700563MultiNodeLogNamer::MultiNodeLogNamer(std::string_view base_name,
Austin Schuha499cea2021-07-31 19:49:53 -0700564 EventLoop *event_loop)
Austin Schuh5b728b72021-06-16 14:57:15 -0700565 : MultiNodeLogNamer(base_name, event_loop->configuration(), event_loop,
566 event_loop->node()) {}
567
568MultiNodeLogNamer::MultiNodeLogNamer(std::string_view base_name,
569 const Configuration *configuration,
570 EventLoop *event_loop, const Node *node)
571 : LogNamer(configuration, event_loop, node),
572 base_name_(base_name),
Austin Schuh8bdfc492023-02-11 12:53:13 -0800573 old_base_name_(),
574 encoder_factory_([](size_t max_message_size) {
575 // TODO(austin): For slow channels, can we allocate less memory?
576 return std::make_unique<DummyEncoder>(max_message_size,
577 FLAGS_flush_size);
578 }) {}
Austin Schuhcb5601b2020-09-10 15:29:59 -0700579
Brian Silverman48deab12020-09-30 18:39:28 -0700580MultiNodeLogNamer::~MultiNodeLogNamer() {
581 if (!ran_out_of_space_) {
582 // This handles renaming temporary files etc.
583 Close();
584 }
585}
586
Austin Schuh572924a2021-07-30 22:32:12 -0700587void MultiNodeLogNamer::Rotate(const Node *node) {
Austin Schuhcb5601b2020-09-10 15:29:59 -0700588 if (node == this->node()) {
Austin Schuhb8bca732021-07-30 22:32:00 -0700589 if (data_writer_) {
Austin Schuh572924a2021-07-30 22:32:12 -0700590 data_writer_->Rotate();
Brian Silvermancb805822020-10-06 17:43:35 -0700591 }
Austin Schuhcb5601b2020-09-10 15:29:59 -0700592 } else {
Austin Schuhb8bca732021-07-30 22:32:00 -0700593 for (std::pair<const Channel *const, NewDataWriter> &data_writer :
Austin Schuhcb5601b2020-09-10 15:29:59 -0700594 data_writers_) {
Austin Schuh572924a2021-07-30 22:32:12 -0700595 if (node == data_writer.second.node()) {
596 data_writer.second.Rotate();
Austin Schuhcb5601b2020-09-10 15:29:59 -0700597 }
598 }
599 }
600}
601
Austin Schuh8c399962020-12-25 21:51:45 -0800602void MultiNodeLogNamer::WriteConfiguration(
603 aos::SizePrefixedFlatbufferDetachedBuffer<LogFileHeader> *header,
604 std::string_view config_sha256) {
605 if (ran_out_of_space_) {
606 return;
607 }
608
609 const std::string_view separator = base_name_.back() == '/' ? "" : "_";
610 const std::string filename = absl::StrCat(
611 base_name_, separator, config_sha256, ".bfbs", extension_, temp_suffix_);
612
613 std::unique_ptr<DetachedBufferWriter> writer =
Austin Schuh48d10d62022-10-16 22:19:23 -0700614 std::make_unique<DetachedBufferWriter>(
615 filename, encoder_factory_(header->span().size()));
Austin Schuh8c399962020-12-25 21:51:45 -0800616
Austin Schuh7ef11a42023-02-04 17:15:12 -0800617 DataEncoder::SpanCopier coppier(header->span());
618 writer->CopyMessage(&coppier, aos::monotonic_clock::now());
Austin Schuh8c399962020-12-25 21:51:45 -0800619
620 if (!writer->ran_out_of_space()) {
Austin Schuh5b728b72021-06-16 14:57:15 -0700621 all_filenames_.emplace_back(
622 absl::StrCat(config_sha256, ".bfbs", extension_));
Austin Schuh8c399962020-12-25 21:51:45 -0800623 }
624 CloseWriter(&writer);
625}
626
Austin Schuhb8bca732021-07-30 22:32:00 -0700627NewDataWriter *MultiNodeLogNamer::MakeWriter(const Channel *channel) {
Austin Schuhcb5601b2020-09-10 15:29:59 -0700628 // See if we can read the data on this node at all.
629 const bool is_readable =
630 configuration::ChannelIsReadableOnNode(channel, this->node());
631 if (!is_readable) {
632 return nullptr;
633 }
634
635 // Then, see if we are supposed to log the data here.
636 const bool log_message =
637 configuration::ChannelMessageIsLoggedOnNode(channel, this->node());
638
639 if (!log_message) {
640 return nullptr;
641 }
642
643 // Now, sort out if this is data generated on this node, or not. It is
644 // generated if it is sendable on this node.
645 if (configuration::ChannelIsSendableOnNode(channel, this->node())) {
Austin Schuhb8bca732021-07-30 22:32:00 -0700646 if (!data_writer_) {
Austin Schuh48d10d62022-10-16 22:19:23 -0700647 MakeDataWriter();
Brian Silvermancb805822020-10-06 17:43:35 -0700648 }
Austin Schuh48d10d62022-10-16 22:19:23 -0700649 data_writer_->UpdateMaxMessageSize(PackMessageSize(
650 LogType::kLogRemoteMessage, channel->max_size()));
Austin Schuhb8bca732021-07-30 22:32:00 -0700651 return data_writer_.get();
Austin Schuhcb5601b2020-09-10 15:29:59 -0700652 }
653
654 // Ok, we have data that is being forwarded to us that we are supposed to
655 // log. It needs to be logged with send timestamps, but be sorted enough
656 // to be able to be processed.
657 CHECK(data_writers_.find(channel) == data_writers_.end());
658
659 // Track that this node is being logged.
660 const Node *source_node = configuration::GetNode(
661 configuration_, channel->source_node()->string_view());
662
663 if (std::find(nodes_.begin(), nodes_.end(), source_node) == nodes_.end()) {
664 nodes_.emplace_back(source_node);
665 }
666
Austin Schuhf5f99f32022-02-07 20:05:37 -0800667 NewDataWriter data_writer(
668 this, source_node, node_,
669 [this, channel](NewDataWriter *data_writer) {
670 OpenWriter(channel, data_writer);
671 },
Austin Schuh48d10d62022-10-16 22:19:23 -0700672 [this](NewDataWriter *data_writer) { CloseWriter(&data_writer->writer); },
673 PackMessageSize(LogType::kLogRemoteMessage, channel->max_size()));
Austin Schuhb8bca732021-07-30 22:32:00 -0700674 return &(
675 data_writers_.emplace(channel, std::move(data_writer)).first->second);
Austin Schuhcb5601b2020-09-10 15:29:59 -0700676}
677
Austin Schuhb8bca732021-07-30 22:32:00 -0700678NewDataWriter *MultiNodeLogNamer::MakeForwardedTimestampWriter(
Austin Schuhcb5601b2020-09-10 15:29:59 -0700679 const Channel *channel, const Node *node) {
680 // See if we can read the data on this node at all.
681 const bool is_readable =
682 configuration::ChannelIsReadableOnNode(channel, this->node());
683 CHECK(is_readable) << ": " << configuration::CleanedChannelToString(channel);
684
685 CHECK(data_writers_.find(channel) == data_writers_.end());
686
687 if (std::find(nodes_.begin(), nodes_.end(), node) == nodes_.end()) {
688 nodes_.emplace_back(node);
689 }
690
Austin Schuhf5f99f32022-02-07 20:05:37 -0800691 NewDataWriter data_writer(
692 this, configuration::GetNode(configuration_, node), node_,
693 [this, channel](NewDataWriter *data_writer) {
694 OpenForwardedTimestampWriter(channel, data_writer);
695 },
Austin Schuh48d10d62022-10-16 22:19:23 -0700696 [this](NewDataWriter *data_writer) { CloseWriter(&data_writer->writer); },
697 PackRemoteMessageSize());
Austin Schuhb8bca732021-07-30 22:32:00 -0700698 return &(
699 data_writers_.emplace(channel, std::move(data_writer)).first->second);
Austin Schuhcb5601b2020-09-10 15:29:59 -0700700}
701
Austin Schuhb8bca732021-07-30 22:32:00 -0700702NewDataWriter *MultiNodeLogNamer::MakeTimestampWriter(const Channel *channel) {
Brian Silverman0465fcf2020-09-24 00:29:18 -0700703 bool log_delivery_times = false;
704 if (this->node() != nullptr) {
705 log_delivery_times = configuration::ConnectionDeliveryTimeIsLoggedOnNode(
706 channel, this->node(), this->node());
707 }
Austin Schuhcb5601b2020-09-10 15:29:59 -0700708 if (!log_delivery_times) {
709 return nullptr;
710 }
711
Austin Schuhb8bca732021-07-30 22:32:00 -0700712 if (!data_writer_) {
Austin Schuh48d10d62022-10-16 22:19:23 -0700713 MakeDataWriter();
Brian Silvermancb805822020-10-06 17:43:35 -0700714 }
Austin Schuh48d10d62022-10-16 22:19:23 -0700715 data_writer_->UpdateMaxMessageSize(
716 PackMessageSize(LogType::kLogDeliveryTimeOnly, 0));
Austin Schuhb8bca732021-07-30 22:32:00 -0700717 return data_writer_.get();
Austin Schuhcb5601b2020-09-10 15:29:59 -0700718}
719
Brian Silverman0465fcf2020-09-24 00:29:18 -0700720void MultiNodeLogNamer::Close() {
Austin Schuhb8bca732021-07-30 22:32:00 -0700721 data_writers_.clear();
722 data_writer_.reset();
Brian Silvermancb805822020-10-06 17:43:35 -0700723}
724
725void MultiNodeLogNamer::ResetStatistics() {
Austin Schuhb8bca732021-07-30 22:32:00 -0700726 for (std::pair<const Channel *const, NewDataWriter> &data_writer :
Brian Silvermancb805822020-10-06 17:43:35 -0700727 data_writers_) {
Austin Schuhad0cfc32020-12-21 12:34:26 -0800728 if (!data_writer.second.writer) continue;
Brian Silvermancb805822020-10-06 17:43:35 -0700729 data_writer.second.writer->ResetStatistics();
Brian Silverman0465fcf2020-09-24 00:29:18 -0700730 }
Austin Schuhb8bca732021-07-30 22:32:00 -0700731 if (data_writer_) {
732 data_writer_->writer->ResetStatistics();
Brian Silvermancb805822020-10-06 17:43:35 -0700733 }
734 max_write_time_ = std::chrono::nanoseconds::zero();
735 max_write_time_bytes_ = -1;
736 max_write_time_messages_ = -1;
737 total_write_time_ = std::chrono::nanoseconds::zero();
738 total_write_count_ = 0;
739 total_write_messages_ = 0;
740 total_write_bytes_ = 0;
Brian Silverman0465fcf2020-09-24 00:29:18 -0700741}
742
Austin Schuhb8bca732021-07-30 22:32:00 -0700743void MultiNodeLogNamer::OpenForwardedTimestampWriter(
744 const Channel *channel, NewDataWriter *data_writer) {
Austin Schuhcb5601b2020-09-10 15:29:59 -0700745 std::string filename =
Austin Schuhe715eae2020-10-10 15:39:30 -0700746 absl::StrCat("timestamps", channel->name()->string_view(), "/",
Brian Silvermana621f522020-09-30 16:52:43 -0700747 channel->type()->string_view(), ".part",
Austin Schuh572924a2021-07-30 22:32:12 -0700748 data_writer->parts_index(), ".bfbs", extension_);
Austin Schuh48d10d62022-10-16 22:19:23 -0700749 CreateBufferWriter(filename, data_writer->max_message_size(),
750 &data_writer->writer);
Austin Schuhcb5601b2020-09-10 15:29:59 -0700751}
752
753void MultiNodeLogNamer::OpenWriter(const Channel *channel,
Austin Schuhb8bca732021-07-30 22:32:00 -0700754 NewDataWriter *data_writer) {
Austin Schuhcb5601b2020-09-10 15:29:59 -0700755 const std::string filename = absl::StrCat(
Austin Schuhe715eae2020-10-10 15:39:30 -0700756 CHECK_NOTNULL(channel->source_node())->string_view(), "_data",
Brian Silvermana621f522020-09-30 16:52:43 -0700757 channel->name()->string_view(), "/", channel->type()->string_view(),
Austin Schuh572924a2021-07-30 22:32:12 -0700758 ".part", data_writer->parts_index(), ".bfbs", extension_);
Austin Schuh48d10d62022-10-16 22:19:23 -0700759 CreateBufferWriter(filename, data_writer->max_message_size(),
760 &data_writer->writer);
Austin Schuhcb5601b2020-09-10 15:29:59 -0700761}
762
Austin Schuh48d10d62022-10-16 22:19:23 -0700763void MultiNodeLogNamer::MakeDataWriter() {
Austin Schuhb8bca732021-07-30 22:32:00 -0700764 if (!data_writer_) {
765 data_writer_ = std::make_unique<NewDataWriter>(
Austin Schuhf5f99f32022-02-07 20:05:37 -0800766 this, node_, node_,
Austin Schuhb8bca732021-07-30 22:32:00 -0700767 [this](NewDataWriter *writer) {
768 std::string name;
769 if (node() != nullptr) {
770 name = absl::StrCat(name, node()->name()->string_view(), "_");
771 }
Austin Schuh572924a2021-07-30 22:32:12 -0700772 absl::StrAppend(&name, "data.part", writer->parts_index(), ".bfbs",
Austin Schuhb8bca732021-07-30 22:32:00 -0700773 extension_);
Austin Schuh48d10d62022-10-16 22:19:23 -0700774 CreateBufferWriter(name, writer->max_message_size(), &writer->writer);
Austin Schuhb8bca732021-07-30 22:32:00 -0700775 },
776 [this](NewDataWriter *data_writer) {
777 CloseWriter(&data_writer->writer);
Austin Schuh48d10d62022-10-16 22:19:23 -0700778 },
779 // Default size is 0 so it will be obvious if something doesn't fix it
780 // afterwards.
781 0);
Brian Silverman7af8c902020-09-29 16:14:04 -0700782 }
Austin Schuhcb5601b2020-09-10 15:29:59 -0700783}
784
Brian Silverman0465fcf2020-09-24 00:29:18 -0700785void MultiNodeLogNamer::CreateBufferWriter(
Austin Schuh48d10d62022-10-16 22:19:23 -0700786 std::string_view path, size_t max_message_size,
787 std::unique_ptr<DetachedBufferWriter> *destination) {
Brian Silverman0465fcf2020-09-24 00:29:18 -0700788 if (ran_out_of_space_) {
789 // Refuse to open any new files, which might skip data. Any existing files
790 // are in the same folder, which means they're on the same filesystem, which
791 // means they're probably going to run out of space and get stuck too.
Austin Schuha426f1f2021-03-31 22:27:41 -0700792 if (!destination->get()) {
793 // But avoid leaving a nullptr writer if we're out of space when
794 // attempting to open the first file.
795 *destination = std::make_unique<DetachedBufferWriter>(
796 DetachedBufferWriter::already_out_of_space_t());
797 }
Brian Silverman0465fcf2020-09-24 00:29:18 -0700798 return;
799 }
Austin Schuhe715eae2020-10-10 15:39:30 -0700800 const std::string_view separator = base_name_.back() == '/' ? "" : "_";
801 const std::string filename =
802 absl::StrCat(base_name_, separator, path, temp_suffix_);
Brian Silverman0465fcf2020-09-24 00:29:18 -0700803 if (!destination->get()) {
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700804 if (ran_out_of_space_) {
805 *destination = std::make_unique<DetachedBufferWriter>(
806 DetachedBufferWriter::already_out_of_space_t());
807 return;
808 }
Austin Schuh48d10d62022-10-16 22:19:23 -0700809 *destination = std::make_unique<DetachedBufferWriter>(
810 filename, encoder_factory_(max_message_size));
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700811 if (!destination->get()->ran_out_of_space()) {
812 all_filenames_.emplace_back(path);
813 }
Brian Silverman0465fcf2020-09-24 00:29:18 -0700814 return;
815 }
Brian Silvermancb805822020-10-06 17:43:35 -0700816
817 CloseWriter(destination);
818 if (ran_out_of_space_) {
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700819 *destination->get() =
820 DetachedBufferWriter(DetachedBufferWriter::already_out_of_space_t());
Brian Silverman0465fcf2020-09-24 00:29:18 -0700821 return;
822 }
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700823
Austin Schuh48d10d62022-10-16 22:19:23 -0700824 *destination->get() =
825 DetachedBufferWriter(filename, encoder_factory_(max_message_size));
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700826 if (!destination->get()->ran_out_of_space()) {
827 all_filenames_.emplace_back(path);
828 }
Brian Silverman0465fcf2020-09-24 00:29:18 -0700829}
830
Brian Silverman48deab12020-09-30 18:39:28 -0700831void MultiNodeLogNamer::RenameTempFile(DetachedBufferWriter *destination) {
832 if (temp_suffix_.empty()) {
833 return;
834 }
Austin Schuh6bb8a822021-03-31 23:04:39 -0700835 std::string current_filename = std::string(destination->filename());
Brian Silverman48deab12020-09-30 18:39:28 -0700836 CHECK(current_filename.size() > temp_suffix_.size());
Austin Schuh6bb8a822021-03-31 23:04:39 -0700837 std::string final_filename =
Brian Silverman48deab12020-09-30 18:39:28 -0700838 current_filename.substr(0, current_filename.size() - temp_suffix_.size());
Austin Schuh6bb8a822021-03-31 23:04:39 -0700839 int result = rename(current_filename.c_str(), final_filename.c_str());
840
841 // When changing the base name, we rename the log folder while there active
842 // buffer writers. Therefore, the name of that active buffer may still refer
843 // to the old file location rather than the new one. This minimized changes to
844 // existing code.
845 if (result != 0 && errno != ENOSPC && !old_base_name_.empty()) {
846 auto offset = current_filename.find(old_base_name_);
847 if (offset != std::string::npos) {
848 current_filename.replace(offset, old_base_name_.length(), base_name_);
849 }
850 offset = final_filename.find(old_base_name_);
851 if (offset != std::string::npos) {
852 final_filename.replace(offset, old_base_name_.length(), base_name_);
853 }
854 result = rename(current_filename.c_str(), final_filename.c_str());
855 }
856
Brian Silverman48deab12020-09-30 18:39:28 -0700857 if (result != 0) {
858 if (errno == ENOSPC) {
859 ran_out_of_space_ = true;
860 return;
861 } else {
862 PLOG(FATAL) << "Renaming " << current_filename << " to " << final_filename
863 << " failed";
864 }
Austin Schuh6bb8a822021-03-31 23:04:39 -0700865 } else {
866 VLOG(1) << "Renamed " << current_filename << " -> " << final_filename;
Brian Silverman48deab12020-09-30 18:39:28 -0700867 }
868}
869
Brian Silvermancb805822020-10-06 17:43:35 -0700870void MultiNodeLogNamer::CloseWriter(
871 std::unique_ptr<DetachedBufferWriter> *writer_pointer) {
872 DetachedBufferWriter *const writer = writer_pointer->get();
873 if (!writer) {
874 return;
875 }
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700876 const bool was_open = writer->is_open();
Brian Silvermancb805822020-10-06 17:43:35 -0700877 writer->Close();
878
879 if (writer->max_write_time() > max_write_time_) {
880 max_write_time_ = writer->max_write_time();
881 max_write_time_bytes_ = writer->max_write_time_bytes();
882 max_write_time_messages_ = writer->max_write_time_messages();
883 }
884 total_write_time_ += writer->total_write_time();
885 total_write_count_ += writer->total_write_count();
886 total_write_messages_ += writer->total_write_messages();
887 total_write_bytes_ += writer->total_write_bytes();
888
889 if (writer->ran_out_of_space()) {
890 ran_out_of_space_ = true;
891 writer->acknowledge_out_of_space();
892 }
Brian Silvermana9f2ec92020-10-06 18:00:53 -0700893 if (was_open) {
894 RenameTempFile(writer);
895 } else {
896 CHECK(access(std::string(writer->filename()).c_str(), F_OK) == -1)
897 << ": File should not exist: " << writer->filename();
898 }
Brian Silvermancb805822020-10-06 17:43:35 -0700899}
900
Austin Schuhcb5601b2020-09-10 15:29:59 -0700901} // namespace logger
902} // namespace aos