#include "AP_Logger_config.h" #if HAL_LOGGING_ENABLED #include "AP_Common/AP_FWVersion.h" #include "LoggerMessageWriter.h" #include #include #include "AP_Logger.h" #if HAL_LOGGER_FENCE_ENABLED #include #endif #if HAL_LOGGER_RALLY_ENABLED #include #endif #define FORCE_VERSION_H_INCLUDE #include "ap_version.h" #undef FORCE_VERSION_H_INCLUDE // the message writers are mainly called at the end of periodic_fullrate() with a budget of 300us // until they are finished calls to Write() will fail so we want to take up as much of // the budget as possible in order that logging can begin in earnest as early as possible #define MIN_LOOP_TIME_REMAINING_FOR_MESSAGE_WRITE_US 50 extern const AP_HAL::HAL& hal; /* LogStartup - these are simple state machines which allow us to * trickle out messages to the log files */ void LoggerMessageWriter::reset() { _finished = false; } bool LoggerMessageWriter::out_of_time_for_writing_messages() const { #if AP_SCHEDULER_ENABLED return AP::scheduler().time_available_usec() < MIN_LOOP_TIME_REMAINING_FOR_MESSAGE_WRITE_US; #else return false; #endif } void LoggerMessageWriter_DFLogStart::reset() { LoggerMessageWriter::reset(); _fmt_done = false; _params_done = false; _writesysinfo.reset(); #if AP_MISSION_ENABLED _writeentiremission.reset(); #endif #if HAL_LOGGER_RALLY_ENABLED _writeallrallypoints.reset(); #endif #if HAL_LOGGER_FENCE_ENABLED _writeallpolyfence.reset(); #endif stage = Stage::FORMATS; next_format_to_send = 0; _next_unit_to_send = 0; _next_multiplier_to_send = 0; _next_format_unit_to_send = 0; param_default = AP::logger().quiet_nanf(); ap = AP_Param::first(&token, &type, ¶m_default); } bool LoggerMessageWriter_DFLogStart::out_of_time_for_writing_messages_df() const { if (stage == Stage::FORMATS) { // write out the FMT messages as fast as we can #if AP_SCHEDULER_ENABLED return AP::scheduler().time_available_usec() == 0; #else return false; #endif } return LoggerMessageWriter::out_of_time_for_writing_messages(); } /* check if we've taken too long in a process() stage return true if we should stop processing now as we are out of time */ bool LoggerMessageWriter_DFLogStart::check_process_limit(uint32_t start_us) { const uint32_t limit_us = 1000U; if (AP_HAL::micros() - start_us > limit_us) { return true; } return false; } void LoggerMessageWriter_DFLogStart::process() { if (out_of_time_for_writing_messages_df()) { return; } // allow any stage to run for max 1ms, to prevent a long loop on arming const uint32_t start_us = AP_HAL::micros(); switch(stage) { case Stage::FORMATS: // write log formats so the log is self-describing while (next_format_to_send < _logger_backend->num_types()) { const auto &s { _logger_backend->structure(next_format_to_send) }; if (_logger_backend->have_emitted_format_for_type((LogMessages)s->msg_type)) { next_format_to_send++; continue; } if (!_logger_backend->Write_Format(s)) { return; // call me again! } next_format_to_send++; if (check_process_limit(start_us)) { return; // call me again! } } _fmt_done = true; stage = Stage::PARMS; FALLTHROUGH; case Stage::PARMS: { while (ap) { if (!_logger_backend->Write_Parameter(ap, token, type, param_default)) { return; } param_default = AP::logger().quiet_nanf(); ap = AP_Param::next_scalar(&token, &type, ¶m_default); if (check_process_limit(start_us)) { return; // call me again! } } _params_done = true; stage = Stage::UNITS; } FALLTHROUGH; case Stage::UNITS: while (_next_unit_to_send < _logger_backend->num_units()) { if (!_logger_backend->Write_Unit(_logger_backend->unit(_next_unit_to_send))) { return; // call me again! } _next_unit_to_send++; if (check_process_limit(start_us)) { return; // call me again! } } stage = Stage::MULTIPLIERS; FALLTHROUGH; case Stage::MULTIPLIERS: while (_next_multiplier_to_send < _logger_backend->num_multipliers()) { if (!_logger_backend->Write_Multiplier(_logger_backend->multiplier(_next_multiplier_to_send))) { return; // call me again! } _next_multiplier_to_send++; if (check_process_limit(start_us)) { return; // call me again! } } stage = Stage::UNITS; FALLTHROUGH; case Stage::FORMAT_UNITS: while (_next_format_unit_to_send < _logger_backend->num_types()) { if (!_logger_backend->Write_Format_Units(_logger_backend->structure(_next_format_unit_to_send))) { return; // call me again! } _next_format_unit_to_send++; if (check_process_limit(start_us)) { return; // call me again! } } stage = Stage::RUNNING_SUBWRITERS; FALLTHROUGH; case Stage::RUNNING_SUBWRITERS: { LoggerMessageWriter *subwriters[] { &_writesysinfo, #if AP_MISSION_ENABLED &_writeentiremission, #endif #if HAL_LOGGER_RALLY_ENABLED &_writeallrallypoints, #endif #if HAL_LOGGER_FENCE_ENABLED &_writeallpolyfence, #endif }; for (auto *sw : subwriters) { if (!sw->finished()) { sw->process(); if (!sw->finished()) { return; } } } stage = Stage::VEHICLE_MESSAGES; FALLTHROUGH; } case Stage::VEHICLE_MESSAGES: // we guarantee 200 bytes of space for the vehicle startup // messages. This allows them to be simple functions rather // than e.g. LoggerMessageWriter-based state machines if (_logger_backend->vehicle_message_writer()) { if (_logger_backend->bufferspace_available() < 200) { return; } (_logger_backend->vehicle_message_writer())(); } stage = Stage::DONE; FALLTHROUGH; case Stage::DONE: break; } _finished = true; } #if AP_MISSION_ENABLED bool LoggerMessageWriter_DFLogStart::writeentiremission() { if (stage != Stage::DONE) { return false; } stage = Stage::RUNNING_SUBWRITERS; _finished = false; _writeentiremission.reset(); return true; } #endif #if HAL_LOGGER_RALLY_ENABLED bool LoggerMessageWriter_DFLogStart::writeallrallypoints() { if (stage != Stage::DONE) { return false; } stage = Stage::RUNNING_SUBWRITERS; _finished = false; _writeallrallypoints.reset(); return true; } #endif #if HAL_LOGGER_FENCE_ENABLED bool LoggerMessageWriter_DFLogStart::writeallfence() { if (stage != Stage::DONE) { return false; } stage = Stage::RUNNING_SUBWRITERS; _finished = false; _writeallpolyfence.reset(); return true; } #endif void LoggerMessageWriter_WriteSysInfo::reset() { LoggerMessageWriter::reset(); stage = Stage::FIRMWARE_STRING; } void LoggerMessageWriter_WriteSysInfo::process() { const AP_FWVersion &fwver = AP::fwversion(); switch(stage) { case Stage::FIRMWARE_STRING: #ifdef AP_CUSTOM_FIRMWARE_STRING // also log original firmware string if different if (! _logger_backend->Write_MessageF("%s [%s]", fwver.fw_string, fwver.fw_string_original)) { return; // call me again } #else if (! _logger_backend->Write_Message(fwver.fw_string)) { return; // call me again } #endif stage = Stage::GIT_VERSIONS; FALLTHROUGH; case Stage::GIT_VERSIONS: if (fwver.middleware_name && fwver.os_name) { if (! _logger_backend->Write_MessageF("%s: %s %s: %s", fwver.middleware_name, fwver.middleware_hash_str, fwver.os_name, fwver.os_hash_str)) { return; // call me again } } else if (fwver.os_name) { if (! _logger_backend->Write_MessageF("%s: %s", fwver.os_name, fwver.os_hash_str)) { return; // call me again } } stage = Stage::VER; FALLTHROUGH; case Stage::VER: { if (!_logger_backend->Write_VER()) { return; } stage = Stage::SYSTEM_ID; FALLTHROUGH; } case Stage::SYSTEM_ID: char sysid[50]; if (hal.util->get_system_id(sysid)) { if (! _logger_backend->Write_Message(sysid)) { return; // call me again } } stage = Stage::PARAM_SPACE_USED; FALLTHROUGH; case Stage::PARAM_SPACE_USED: if (! _logger_backend->Write_MessageF("Param space used: %u/%u", AP_Param::storage_used(), AP_Param::storage_size())) { return; // call me again } stage = Stage::RC_PROTOCOL; FALLTHROUGH; case Stage::RC_PROTOCOL: { const char *prot = hal.rcin->protocol(); if (prot == nullptr) { prot = "None"; } if (! _logger_backend->Write_MessageF("RC Protocol: %s", prot)) { return; // call me again } stage = Stage::RC_OUTPUT; FALLTHROUGH; } case Stage::RC_OUTPUT: { char banner_msg[50]; if (hal.rcout->get_output_mode_banner(banner_msg, sizeof(banner_msg))) { if (!_logger_backend->Write_Message(banner_msg)) { return; // call me again } } break; } } _finished = true; // all done! } #if HAL_LOGGER_RALLY_ENABLED void LoggerMessageWriter_WriteAllRallyPoints::process() { const AP_Rally *_rally = AP::rally(); if (_rally == nullptr) { _finished = true; return; } switch(stage) { case Stage::WRITE_NEW_RALLY_MESSAGE: if (! _logger_backend->Write_Message("New rally")) { return; // call me again } stage = Stage::WRITE_ALL_RALLY_POINTS; FALLTHROUGH; case Stage::WRITE_ALL_RALLY_POINTS: while (_rally_number_to_send < _rally->get_rally_total()) { if (out_of_time_for_writing_messages()) { return; } RallyLocation rallypoint; if (_rally->get_rally_point_with_index(_rally_number_to_send, rallypoint)) { if (!_logger_backend->Write_RallyPoint( _rally->get_rally_total(), _rally_number_to_send, rallypoint)) { return; // call me again } } _rally_number_to_send++; } stage = Stage::DONE; FALLTHROUGH; case Stage::DONE: break; } _finished = true; } void LoggerMessageWriter_WriteAllRallyPoints::reset() { LoggerMessageWriter::reset(); stage = Stage::WRITE_NEW_RALLY_MESSAGE; _rally_number_to_send = 0; } #endif // HAL_LOGGER_RALLY_ENABLED void LoggerMessageWriter_WriteEntireMission::process() { const AP_Mission *_mission = AP::mission(); if (_mission == nullptr) { _finished = true; return; } switch(stage) { case Stage::WRITE_NEW_MISSION_MESSAGE: if (! _logger_backend->Write_Message("New mission")) { return; // call me again } stage = Stage::WRITE_MISSION_ITEMS; FALLTHROUGH; case Stage::WRITE_MISSION_ITEMS: { AP_Mission::Mission_Command cmd; while (_mission_number_to_send < _mission->num_commands()) { if (out_of_time_for_writing_messages()) { return; } // upon failure to write the mission we will re-read from // storage; this could be improved. if (_mission->read_cmd_from_storage(_mission_number_to_send,cmd)) { if (!_logger_backend->Write_Mission_Cmd(*_mission, cmd)) { return; // call me again } } _mission_number_to_send++; } stage = Stage::DONE; FALLTHROUGH; } case Stage::DONE: break; } _finished = true; } void LoggerMessageWriter_WriteEntireMission::reset() { LoggerMessageWriter::reset(); stage = Stage::WRITE_NEW_MISSION_MESSAGE; _mission_number_to_send = 0; } #if HAL_LOGGER_FENCE_ENABLED #if APM_BUILD_TYPE(APM_BUILD_Replay) // dummy methods to allow build with Replay void LoggerMessageWriter_Write_Polyfence::process() { }; void LoggerMessageWriter_Write_Polyfence::reset() { }; #else void LoggerMessageWriter_Write_Polyfence::process() { AC_Fence *fence = AP::fence(); if (fence == nullptr) { _finished = true; return; } switch(stage) { case Stage::WRITE_NEW_FENCE_MESSAGE: if (!_logger_backend->Write_Message("New fence")) { return; // call me again } stage = Stage::WRITE_FENCE_ITEMS; FALLTHROUGH; case Stage::WRITE_FENCE_ITEMS: { while (_fence_number_to_send < fence->polyfence().num_stored_items()) { if (out_of_time_for_writing_messages()) { return; } // upon failure to write the fence we will re-read from // storage; this could be improved. AC_PolyFenceItem fenceitem {}; if (fence->polyfence().get_item(_fence_number_to_send, fenceitem)) { if (!_logger_backend->Write_FencePoint(fence->polyfence().num_stored_items(), _fence_number_to_send, fenceitem)) { return; // call me again } } _fence_number_to_send++; } stage = Stage::DONE; FALLTHROUGH; } case Stage::DONE: break; } _finished = true; } void LoggerMessageWriter_Write_Polyfence::reset() { LoggerMessageWriter::reset(); stage = Stage::WRITE_NEW_FENCE_MESSAGE; _fence_number_to_send = 0; } #endif // !APM_BUILD_TYPE(APM_BUILD_Replay) #endif // AP_FENCE_ENABLED #endif // HAL_LOGGING_ENABLED