James Kuszmaul | cf32412 | 2023-01-14 14:07:17 -0800 | [diff] [blame^] | 1 | // Copyright (c) FIRST and other WPILib contributors. |
| 2 | // Open Source Software; you can modify and/or share it under the terms of |
| 3 | // the WPILib BSD license file in the root directory of this project. |
| 4 | |
| 5 | #include "frc/DataLogManager.h" |
| 6 | |
| 7 | #include <algorithm> |
| 8 | #include <ctime> |
| 9 | #include <random> |
| 10 | |
| 11 | #include <fmt/chrono.h> |
| 12 | #include <fmt/format.h> |
| 13 | #include <networktables/NetworkTableInstance.h> |
| 14 | #include <wpi/DataLog.h> |
| 15 | #include <wpi/SafeThread.h> |
| 16 | #include <wpi/StringExtras.h> |
| 17 | #include <wpi/fs.h> |
| 18 | #include <wpi/timestamp.h> |
| 19 | |
| 20 | #include "frc/DriverStation.h" |
| 21 | #include "frc/Filesystem.h" |
| 22 | |
| 23 | using namespace frc; |
| 24 | |
| 25 | namespace { |
| 26 | |
| 27 | struct Thread final : public wpi::SafeThread { |
| 28 | Thread(std::string_view dir, std::string_view filename, double period); |
| 29 | |
| 30 | void Main() final; |
| 31 | |
| 32 | void StartNTLog(); |
| 33 | void StopNTLog(); |
| 34 | |
| 35 | std::string m_logDir; |
| 36 | bool m_filenameOverride; |
| 37 | wpi::log::DataLog m_log; |
| 38 | bool m_ntLoggerEnabled = false; |
| 39 | NT_DataLogger m_ntEntryLogger = 0; |
| 40 | NT_ConnectionDataLogger m_ntConnLogger = 0; |
| 41 | wpi::log::StringLogEntry m_messageLog; |
| 42 | }; |
| 43 | |
| 44 | struct Instance { |
| 45 | Instance(std::string_view dir, std::string_view filename, double period); |
| 46 | wpi::SafeThreadOwner<Thread> owner; |
| 47 | }; |
| 48 | |
| 49 | } // namespace |
| 50 | |
| 51 | // if less than this much free space, delete log files until there is this much |
| 52 | // free space OR there are this many files remaining. |
| 53 | static constexpr uintmax_t kFreeSpaceThreshold = 50000000; |
| 54 | static constexpr int kFileCountThreshold = 10; |
| 55 | |
| 56 | static std::string MakeLogDir(std::string_view dir) { |
| 57 | if (!dir.empty()) { |
| 58 | return std::string{dir}; |
| 59 | } |
| 60 | #ifdef __FRC_ROBORIO__ |
| 61 | // prefer a mounted USB drive if one is accessible |
| 62 | constexpr std::string_view usbDir{"/u"}; |
| 63 | std::error_code ec; |
| 64 | auto s = fs::status(usbDir, ec); |
| 65 | if (!ec && fs::is_directory(s) && |
| 66 | (s.permissions() & fs::perms::others_write) != fs::perms::none) { |
| 67 | return std::string{usbDir}; |
| 68 | } |
| 69 | #endif |
| 70 | return frc::filesystem::GetOperatingDirectory(); |
| 71 | } |
| 72 | |
| 73 | static std::string MakeLogFilename(std::string_view filenameOverride) { |
| 74 | if (!filenameOverride.empty()) { |
| 75 | return std::string{filenameOverride}; |
| 76 | } |
| 77 | static std::random_device dev; |
| 78 | static std::mt19937 rng(dev()); |
| 79 | std::uniform_int_distribution<int> dist(0, 15); |
| 80 | const char* v = "0123456789abcdef"; |
| 81 | std::string filename = "FRC_TBD_"; |
| 82 | for (int i = 0; i < 16; i++) { |
| 83 | filename += v[dist(rng)]; |
| 84 | } |
| 85 | filename += ".wpilog"; |
| 86 | return filename; |
| 87 | } |
| 88 | |
| 89 | Thread::Thread(std::string_view dir, std::string_view filename, double period) |
| 90 | : m_logDir{dir}, |
| 91 | m_filenameOverride{!filename.empty()}, |
| 92 | m_log{dir, MakeLogFilename(filename), period}, |
| 93 | m_messageLog{m_log, "messages"} { |
| 94 | StartNTLog(); |
| 95 | } |
| 96 | |
| 97 | void Thread::Main() { |
| 98 | // based on free disk space, scan for "old" FRC_*.wpilog files and remove |
| 99 | { |
| 100 | uintmax_t freeSpace = fs::space(m_logDir).free; |
| 101 | if (freeSpace < kFreeSpaceThreshold) { |
| 102 | // Delete oldest FRC_*.wpilog files (ignore FRC_TBD_*.wpilog as we just |
| 103 | // created one) |
| 104 | std::vector<fs::directory_entry> entries; |
| 105 | std::error_code ec; |
| 106 | for (auto&& entry : fs::directory_iterator{m_logDir, ec}) { |
| 107 | auto stem = entry.path().stem().string(); |
| 108 | if (wpi::starts_with(stem, "FRC_") && |
| 109 | entry.path().extension() == ".wpilog" && |
| 110 | !wpi::starts_with(stem, "FRC_TBD_")) { |
| 111 | entries.emplace_back(entry); |
| 112 | } |
| 113 | } |
| 114 | std::sort(entries.begin(), entries.end(), |
| 115 | [](const auto& a, const auto& b) { |
| 116 | return a.last_write_time() < b.last_write_time(); |
| 117 | }); |
| 118 | |
| 119 | int count = entries.size(); |
| 120 | for (auto&& entry : entries) { |
| 121 | --count; |
| 122 | if (count < kFileCountThreshold) { |
| 123 | break; |
| 124 | } |
| 125 | auto size = entry.file_size(); |
| 126 | if (fs::remove(entry.path(), ec)) { |
| 127 | freeSpace += size; |
| 128 | if (freeSpace >= kFreeSpaceThreshold) { |
| 129 | break; |
| 130 | } |
| 131 | } else { |
| 132 | fmt::print(stderr, "DataLogManager: could not delete {}\n", |
| 133 | entry.path().string()); |
| 134 | } |
| 135 | } |
| 136 | } |
| 137 | } |
| 138 | |
| 139 | int timeoutCount = 0; |
| 140 | bool paused = false; |
| 141 | int dsAttachCount = 0; |
| 142 | int fmsAttachCount = 0; |
| 143 | bool dsRenamed = m_filenameOverride; |
| 144 | bool fmsRenamed = m_filenameOverride; |
| 145 | int sysTimeCount = 0; |
| 146 | wpi::log::IntegerLogEntry sysTimeEntry{ |
| 147 | m_log, "systemTime", |
| 148 | "{\"source\":\"DataLogManager\",\"format\":\"time_t_us\"}"}; |
| 149 | |
| 150 | wpi::Event newDataEvent; |
| 151 | DriverStation::ProvideRefreshedDataEventHandle(newDataEvent.GetHandle()); |
| 152 | |
| 153 | for (;;) { |
| 154 | bool timedOut = false; |
| 155 | bool newData = |
| 156 | wpi::WaitForObject(newDataEvent.GetHandle(), 0.25, &timedOut); |
| 157 | if (!m_active) { |
| 158 | break; |
| 159 | } |
| 160 | if (!newData) { |
| 161 | ++timeoutCount; |
| 162 | // pause logging after being disconnected for 10 seconds |
| 163 | if (timeoutCount > 40 && !paused) { |
| 164 | timeoutCount = 0; |
| 165 | paused = true; |
| 166 | m_log.Pause(); |
| 167 | } |
| 168 | continue; |
| 169 | } |
| 170 | // when we connect to the DS, resume logging |
| 171 | timeoutCount = 0; |
| 172 | if (paused) { |
| 173 | paused = false; |
| 174 | m_log.Resume(); |
| 175 | } |
| 176 | |
| 177 | if (!dsRenamed) { |
| 178 | // track DS attach |
| 179 | if (DriverStation::IsDSAttached()) { |
| 180 | ++dsAttachCount; |
| 181 | } else { |
| 182 | dsAttachCount = 0; |
| 183 | } |
| 184 | if (dsAttachCount > 50) { // 1 second |
| 185 | std::time_t now = std::time(nullptr); |
| 186 | auto tm = std::gmtime(&now); |
| 187 | if (tm->tm_year > 100) { |
| 188 | // assume local clock is now synchronized to DS, so rename based on |
| 189 | // local time |
| 190 | m_log.SetFilename(fmt::format("FRC_{:%Y%m%d_%H%M%S}.wpilog", *tm)); |
| 191 | dsRenamed = true; |
| 192 | } else { |
| 193 | dsAttachCount = 0; // wait a bit and try again |
| 194 | } |
| 195 | } |
| 196 | } |
| 197 | |
| 198 | if (!fmsRenamed) { |
| 199 | // track FMS attach |
| 200 | if (DriverStation::IsFMSAttached()) { |
| 201 | ++fmsAttachCount; |
| 202 | } else { |
| 203 | fmsAttachCount = 0; |
| 204 | } |
| 205 | if (fmsAttachCount > 100) { // 2 seconds |
| 206 | // match info comes through TCP, so we need to double-check we've |
| 207 | // actually received it |
| 208 | auto matchType = DriverStation::GetMatchType(); |
| 209 | if (matchType != DriverStation::kNone) { |
| 210 | // rename per match info |
| 211 | char matchTypeChar; |
| 212 | switch (matchType) { |
| 213 | case DriverStation::kPractice: |
| 214 | matchTypeChar = 'P'; |
| 215 | break; |
| 216 | case DriverStation::kQualification: |
| 217 | matchTypeChar = 'Q'; |
| 218 | break; |
| 219 | case DriverStation::kElimination: |
| 220 | matchTypeChar = 'E'; |
| 221 | break; |
| 222 | default: |
| 223 | matchTypeChar = '_'; |
| 224 | break; |
| 225 | } |
| 226 | std::time_t now = std::time(nullptr); |
| 227 | m_log.SetFilename( |
| 228 | fmt::format("FRC_{:%Y%m%d_%H%M%S}_{}_{}{}.wpilog", |
| 229 | *std::gmtime(&now), DriverStation::GetEventName(), |
| 230 | matchTypeChar, DriverStation::GetMatchNumber())); |
| 231 | fmsRenamed = true; |
| 232 | dsRenamed = true; // don't override FMS rename |
| 233 | } |
| 234 | } |
| 235 | } |
| 236 | |
| 237 | // Write system time every ~5 seconds |
| 238 | ++sysTimeCount; |
| 239 | if (sysTimeCount >= 250) { |
| 240 | sysTimeCount = 0; |
| 241 | sysTimeEntry.Append(wpi::GetSystemTime(), wpi::Now()); |
| 242 | } |
| 243 | } |
| 244 | DriverStation::RemoveRefreshedDataEventHandle(newDataEvent.GetHandle()); |
| 245 | } |
| 246 | |
| 247 | void Thread::StartNTLog() { |
| 248 | if (!m_ntLoggerEnabled) { |
| 249 | m_ntLoggerEnabled = true; |
| 250 | auto inst = nt::NetworkTableInstance::GetDefault(); |
| 251 | m_ntEntryLogger = inst.StartEntryDataLog(m_log, "", "NT:"); |
| 252 | m_ntConnLogger = inst.StartConnectionDataLog(m_log, "NTConnection"); |
| 253 | } |
| 254 | } |
| 255 | |
| 256 | void Thread::StopNTLog() { |
| 257 | if (m_ntLoggerEnabled) { |
| 258 | m_ntLoggerEnabled = false; |
| 259 | nt::NetworkTableInstance::StopEntryDataLog(m_ntEntryLogger); |
| 260 | nt::NetworkTableInstance::StopConnectionDataLog(m_ntConnLogger); |
| 261 | } |
| 262 | } |
| 263 | |
| 264 | Instance::Instance(std::string_view dir, std::string_view filename, |
| 265 | double period) { |
| 266 | // Delete all previously existing FRC_TBD_*.wpilog files. These only exist |
| 267 | // when the robot never connects to the DS, so they are very unlikely to |
| 268 | // have useful data and just clutter the filesystem. |
| 269 | auto logDir = MakeLogDir(dir); |
| 270 | std::error_code ec; |
| 271 | for (auto&& entry : fs::directory_iterator{logDir, ec}) { |
| 272 | if (wpi::starts_with(entry.path().stem().string(), "FRC_TBD_") && |
| 273 | entry.path().extension() == ".wpilog") { |
| 274 | if (!fs::remove(entry, ec)) { |
| 275 | fmt::print(stderr, "DataLogManager: could not delete {}\n", |
| 276 | entry.path().string()); |
| 277 | } |
| 278 | } |
| 279 | } |
| 280 | |
| 281 | owner.Start(logDir, filename, period); |
| 282 | } |
| 283 | |
| 284 | static Instance& GetInstance(std::string_view dir = "", |
| 285 | std::string_view filename = "", |
| 286 | double period = 0.25) { |
| 287 | static Instance instance(dir, filename, period); |
| 288 | return instance; |
| 289 | } |
| 290 | |
| 291 | void DataLogManager::Start(std::string_view dir, std::string_view filename, |
| 292 | double period) { |
| 293 | GetInstance(dir, filename, period); |
| 294 | } |
| 295 | |
| 296 | void DataLogManager::Log(std::string_view message) { |
| 297 | GetInstance().owner.GetThread()->m_messageLog.Append(message); |
| 298 | fmt::print("{}\n", message); |
| 299 | } |
| 300 | |
| 301 | wpi::log::DataLog& DataLogManager::GetLog() { |
| 302 | return GetInstance().owner.GetThread()->m_log; |
| 303 | } |
| 304 | |
| 305 | std::string DataLogManager::GetLogDir() { |
| 306 | return GetInstance().owner.GetThread()->m_logDir; |
| 307 | } |
| 308 | |
| 309 | void DataLogManager::LogNetworkTables(bool enabled) { |
| 310 | if (auto thr = GetInstance().owner.GetThread()) { |
| 311 | if (enabled) { |
| 312 | thr->StartNTLog(); |
| 313 | } else if (!enabled) { |
| 314 | thr->StopNTLog(); |
| 315 | } |
| 316 | } |
| 317 | } |