/** \file * * ESPComponent class implementation. * * Copyright (c) 2015 MBARI * MBARI Proprietary Information. All Rights Reserved */ /** * Testing with simulators on bufflehead and tethyscode: * * See example of complete session at https://bitbucket.org/snippets/carueda/8KR6B * including all relevant settings. */ #include "supervisor/CommandLine.h" // *** DEBUG #include "data/ConfigReader.h" #include "data/Slate.h" #include "data/StrValue.h" #include "data/UniversalDataWriter.h" #include #include #include "ESPComponent.h" #include "ESPComponentIF.h" /**************************************************************************** Communication with the ESP is established in the STARTING state. Once established, the component goes to the RUNNABLE state, where a complete sampling phase in interaction with the ESP is executed. This sampling sequence is controlled by ESPClient. ****************************************************************************/ /* * ESPCOMPONENT_MANUAL_ESP: Optional environment variable only for development/testing purposes. * Usage example: * * $ ESPCOMPONENT_MANUAL_ESP=1 bin/LRAUV -r -x "load Maintenance/sample.xml;..." * * This will indicate that the ESP server will be started manually to connect as a * client to the LRAUV. This helps avoiding unnecessary operations (powering up/down * the ESP, consoleUart, uart, etc.), whose triggered errors would prevent the * simulated exercise from proceeding. */ static bool manualEsp_ = false; // actually assigned in constructor below. ESPComponent::ESPComponent( const Module* module ) : SyncSensorComponent( ESPComponentIF::NAME, module ), startState_( SS_INIT ), espComm_( 0 ), espClient_( 0 ), partialLine_( "" ), uart_( ESPComponentIF::UART, ESPComponentIF::BAUD, 0.2, logger_ ), consoleUart_( ESPComponentIF::CONSOLEUART, ESPComponentIF::BAUD, 0.2, logger_ ), loadControl_( ESPComponentIF::LOAD_CONTROL, !simulateHardware(), logger_, this ), loadControl2_( ESPComponentIF::LOAD_CONTROL2, !simulateHardware(), logger_, this ), espAlwaysServer_( false ), lineTimeout_( 10 ), upsyncTimeout_( 300 ), // allow time for ESP logfile sync to complete before shutdown. overwritten by config value. upsyncTime_( Timestamp::NOT_SET_TIME ), upsyncRequested_( false ), samplingActive_( false ), sampleNumber_( 0 ), debug_( false ), espLogSummaryReported_( false ) { // Read configs for PPP. // TODO handle these with config readers as the others below Slate::ReadOnce( ESPComponentIF::PPP_CONNECT, connectExec_, logger_ ); Slate::ReadOnce( ESPComponentIF::PPP_FLOW, pppFlow_, logger_ ); Slate::ReadOnce( ESPComponentIF::UART, uartName_, logger_ ); // instantiate the config readers connectTimeoutCfgReader_ = newConfigReader( ESPComponentIF::CONNECT_TIMEOUT_CFG ); debugCfgReader_ = newConfigReader( ESPComponentIF::DEBUG_CFG ); espLogFilterRegexReader_ = newConfigReader( ESPComponentIF::ESP_LOG_FILTER_REGEX_CFG ); espServerHostCfgReader_ = newConfigReader( ESPComponentIF::ESP_SERVER_HOST_CFG ); filterResultTimeoutCfgReader_ = newConfigReader( ESPComponentIF::FILTER_RESULT_TIMEOUT_CFG ); initialPromptTimeoutCfgReader_ = newConfigReader( ESPComponentIF::INITIAL_PROMPT_TIMEOUT_CFG ); loadCartridgeTimeoutCfgReader_ = newConfigReader( ESPComponentIF::LOAD_CARTRIDGE_TIMEOUT_CFG ); poTimeoutCfgReader_ = newConfigReader( ESPComponentIF::PO_TIMEOUT_CFG ); processResultTimeoutCfgReader_ = newConfigReader( ESPComponentIF::PROCESS_RESULT_TIMEOUT_CFG ); sampleTimeoutCfgReader_ = newConfigReader( ESPComponentIF::SAMPLE_TIMEOUT_CFG ); socketServerPortCfgReader_ = newConfigReader( ESPComponentIF::SOCKET_SERVER_PORT_CFG ); stopResultTimeoutCfgReader_ = newConfigReader( ESPComponentIF::STOP_RESULT_TIMEOUT_CFG ); upsyncTimeoutCfgReader_ = newConfigReader( ESPComponentIF::UPSYNC_TIMEOUT_CFG ); cartridgeArgumentReader_ = newDataReader( ESPComponentIF::CARTRIDGE ); // TODO the readConfigs below should probably be moved to the 'start' state. // read configs: readConfigs(); samplingActiveWriter_ = newDataWriter( ESPComponentIF::SAMPLING_ACTIVE_STATE ); sampleVolumeWriter_ = newDataWriter( ESPComponentIF::SAMPLE_VOLUME ); sampleNumberWriter_ = newDataWriter( ESPComponentIF::SAMPLE_NUMBER ); stopSamplingReader_ = newDataReader( ESPComponentIF::STOP_SAMPLING ); stopSamplingWriter_ = newDataWriter( ESPComponentIF::STOP_SAMPLING ); setRunState( STOPPED ); this->setFailureMissionCritical( true ); this->setAllowableFailures( 3 ); this->setRetryTimeout( 250 ); manualEsp_ = ::getenv( "ESPCOMPONENT_MANUAL_ESP" ) != 0; if( manualEsp_ ) { logger_.syslog( "ESPCOMPONENT_MANUAL_ESP INDICATED.", Syslog::IMPORTANT ); } } void ESPComponent::createESPComm() { if( espComm_ != 0 ) { logger_.syslog( "WARN: espComm_ expected to be null in createESPComm. please report this bug", Syslog::ERROR ); delete espComm_; espComm_ = 0; } Str espServerHostStr = espServerHost_.asString(); if( espServerHostStr.length() == 0 ) { // LRAUV is the socket-level server; ESP will connect as client espComm_ = new ESPComm( "LRAUV", socketServerPort_, logger_ ); espAlwaysServer_ = false; } else { // ESP is socket-level server; LRAUV will connect as client. // Scan string for hostname:portNumber char hostname[espServerHostStr.length()]; int port = -1; sscanf( espServerHostStr.cStr(), "%[^:]:%d", hostname, &port ); if( port <= 0 ) { logger_.syslog( Str( "createESPComm: the given non-empty espServerHost value \"" ) + espServerHostStr + "\" does not have format \"hostname:portNumber\" (with portNumber>0)", Syslog::FAULT ); } else { if( debug_ ) logDebug( Str( "createESPComm: connecting to " ) + hostname + ":" + port ); espComm_ = new ESPComm( "LRAUV", hostname, port, logger_ ); espAlwaysServer_ = true; } } if( espComm_ != 0 ) { espComm_->setDebug( debug_ ); Str espLogFilterRegexStr = espLogFilterRegexStr_.asString(); if( espLogFilterRegexStr.length() > 0 ) { logger_.syslog( Str( "Setting regex for ESP Log summary: '" ) + espLogFilterRegexStr + "'", Syslog::IMPORTANT ); espComm_->setEspLogFilterRegex( espLogFilterRegexStr.cStr() ); } } } ESPComponent::~ESPComponent() { if( espClient_ != 0 ) { delete espClient_; } if( espComm_ != 0 ) { delete espComm_; } } void ESPComponent::run() { //logDebug( "Run" ); } /// /// Creates espComm_ object, if not already created; /// and then transitions to STARTING. /// Component::RunState ESPComponent::start() { if( debug_ ) logDebug( Str( "start simulateHardware()=" ) + simulateHardware() ); if( simulateHardware() ) { return STARTING; } Component::RunState nextRunState; if( handleStopSamplingRequest( nextRunState ) ) { return nextRunState; } if( espComm_ == 0 ) { createESPComm(); } if( espComm_ == 0 ) { logger_.syslog( "Failed to create ESPComm object", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); return STOPPED; // TODO: review } espLogSummaryReported_ = false; espComm_->resetEspLogSummaryLines(); // Close if comms is open if( espComm_->isReadable() ) { espComm_->close(); return START; } if( !isDataRequested() ) { return STOP; } // TETHYS-612. While relying on the regular failCount/allowableFailures mechanism, // we just incorporate a general wait before the power-up/connection sequence. // In particular, such wait is at least as requested right after a power-down. if( startPoRetryWait_ ) delete startPoRetryWait_; startPoRetryWait_ = new Timestamp( Timestamp::Now() ); logDebug( Str( "(612) Will wait for " ) + poRetryWait_.toString() + " before power-up/connection sequence" ); return STARTING; } bool ESPComponent::openServerSocket() { if( espComm_->open().hasError() ) { logger_.syslog( Str( "Error in ESPComm::open: " ) + espComm_->errorString() + ": " + espComm_->getErrorDetail() ); return false; } return true; // ok } bool ESPComponent::powerUpESP() { if( manualEsp_ ) { logger_.syslog( "powerUpESP IGNORED because manualEsp_", Syslog::IMPORTANT ); return true; } if( !espAlwaysServer_ ) { logger_.syslog( "powering up ESP", Syslog::INFO ); Timespan::Milliseconds( 15 ).sleepFor(); if( !loadControl_.powerUp() ) { logger_.syslog( "Failed to power up", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); return false; } // Deisolate comms. The syslog call below is needed for powerUp() calls to work. Seems to be a timing issue, so don't remove until we figure out root cause. logger_.syslog( "powering up ESP secondary power supply", Syslog::INFO ); Timespan::Milliseconds( 15 ).sleepFor(); if( !loadControl2_.powerUp() ) { logger_.syslog( "Failed to power up secondary load control board", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); return false; } } else { logger_.syslog( "ESP set as Always Server, NOT powering up.", Syslog::INFO ); } // Initiate the PPP link startPPP(); return true; // ok } bool ESPComponent::powerDownESP( bool setFailure ) { if( manualEsp_ ) { logger_.syslog( "powerDownESP IGNORED because manualEsp_", Syslog::IMPORTANT ); return true; } logger_.syslog( "powering down ESP", Syslog::INFO ); if( !espAlwaysServer_ && !loadControl_.powerDown() ) { if( setFailure ) { logger_.syslog( "Failed to power down", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); } else { logDebug( "powerDownESP: loadControl_.powerDown() returned false" ); } return false; } logger_.syslog( "powering down ESP secondary power supply", Syslog::INFO ); if( !espAlwaysServer_ && !loadControl2_.powerDown() ) { if( setFailure ) { logger_.syslog( "Failed to power down secondary", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); } else { logDebug( "secondary powerDownESP: loadControl_.powerDown() returned false" ); } return false; } // Bring down the PPP link stopPPP(); return true; // ok } /// /// Handles the "establish connection" state machine, that is, the transition through /// the states indicated by the StartState enum, whose final normal state, SS_CONNECTED, /// in turn triggers the transition to LRAUV framework's RUNNABLE state. /// Component::RunState ESPComponent::starting() { //logDebug( "ESPComponent::starting" ); Component::RunState nextRunState; if( handleStopSamplingRequest( nextRunState ) ) { return nextRunState; } if( simulateHardware() ) { return RUNNABLE; } // We're operating on real hardware from here down if( !logVoltageAndCurrent() ) { return STOP; } if( debug_ ) { logDebug( Str( "ESPComponent::starting: startState_=" ) + startStateName( startState_ ) ); } switch( startState_ ) { case SS_INIT: { // TETHYS-612: if( startPoRetryWait_ ) { if( startPoRetryWait_->elapsed() <= poRetryWait_ ) { return STARTING; } else { delete startPoRetryWait_; startPoRetryWait_ = 0; logDebug( "(612) Done with wait. Will continue with general power-up/connection sequence" ); } } // if( loadControl_->getPowerState() == LoadControl::ON && espComm_->hasEspServerAddressAndPort() ) //Will add later // do we already know where the ESP is (probably) running? if( espComm_->hasEspServerAddressAndPort() ) { // Yes, we have ESP's host and port. // // A possible case in which we know the ESP server address and port is from a previous // connection in which we were the server and the ESP the client (ie., we got the peer // address and the ESP reported its port in a first line in that connection). // The other case is when the config ESPComponent.espServerHost is given (espAlwaysServer_ == true). // Whatever the case, here we try to connect as client in case the ESP is up and running on // the known host:port. If this ends up failing (see actual timeout condition under SS_CONNECTING_AS_CLIENT // below), then we recreate the ESPComm and try again. // startTimeConnecting_ = Timestamp::Now(); startState_ = SS_CONNECTING_AS_CLIENT; logger_.syslog( "ESPComponent: connecting to the ESP at: " + espComm_->showEspServerAddressAndPort(), Syslog::IMPORTANT ); } else { // set things up with vehicle as the tcp server: if( !openServerSocket() ) { logger_.syslog( "Error opening server socket", Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); return START; } if( !manualEsp_ ) { // Here we open the console uart to hold the line which avoids ghost characters on the ESP's cosole input consoleUart_.open(); if( consoleUart_.hasError() ) { logger_.syslog( "Error opening console port: ", consoleUart_.errorString(), Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); return STOP; } } if( !powerUpESP() ) return STOP; startTimeAccept_ = Timestamp::Now(); logger_.syslog( "Waiting for ESP to connect (timeout=" + poTimeout_.toString() + ")", Syslog::IMPORTANT ); startState_ = SS_WAITING_FOR_ESP_TO_CONNECT; } return STARTING; } case SS_CONNECTING_AS_CLIENT: { if( startTimeConnecting_.elapsed() < connectTimeout_ ) { if( debug_ ) logDebug( "ESPComponent: connecting to the ESP at: " + espComm_->showEspServerAddressAndPort() ); if( espComm_->connectAsClient( 200 ).hasError() ) { if( espComm_->getError() == ESPComm::TIMEOUT_CONNECTING ) { if( debug_ ) logDebug( "TIMEOUT_CONNECTING, will retry next cycle" ); return STARTING; // ok, retry next cycle. } else { // some actual error logger_.syslog( "Error while trying to connect to ESP", Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); startState_ = SS_INIT; return STOP; } } else { logger_.syslog( "Connected as client to the ESP server", Syslog::IMPORTANT ); startState_ = SS_CONNECTED; return STARTING; } } else { // actual timeout. if( debug_ ) { Str msg = "Timeout while trying to connect as client to the ESP."; msg += " startTimeConnecting_.elapsed=" + startTimeConnecting_.elapsed().toString(); logDebug( msg ); } // we proceed by basically recreating the ESPComm_ object and transitioning to // SS_INIT to re-try connection: // 1- recreate ESPComm_ object: delete espComm_; espComm_ = 0; createESPComm(); // 2- power down the ESP, and stop PPP link: powerDownESP( false ); // do not worry about possible errors here. // 3- transition to SS_INIT to re-try connection startState_ = SS_INIT; return STARTING; } } case SS_WAITING_FOR_ESP_TO_CONNECT: { // wait for ESP to connect to us: if( !espComm_->isClientConnected() ) { if( !manualEsp_ ) { // Grab (and potentially log if desired) anything on the console port if( consoleUart_.dataAvailable() > 0 ) { consoleUart_.readLine( deviceResponse_, sizeof( deviceResponse_ ) ); logger_.syslog( "console:", deviceResponse_, Syslog::INFO ); } } return waitForESPConnection(); } // ESP has connected. logger_.syslog( "ESP has connected as client", Syslog::IMPORTANT ); // Wait for line indicating server port number: startTimeForLine_ = Timestamp::Now(); startState_ = SS_WAITING_FOR_PORT_NUMBER; return STARTING; } case SS_WAITING_FOR_PORT_NUMBER: { Str line; int ret = getLine( line ); if( ret <= 0 ) { return ret == 0 ? STARTING : STOP; } if( debug_ ) { Str escaped = espComm_->escape( line.cStr(), line.length() ); Str msg = Str( startStateName( startState_ ) ); msg += Str( " line=\"" ) + escaped + "\""; logDebug( msg ); } // the received line expected to contain the port of the ESP as a server: int espServerPort = -1; if( scanEspServerPort( line, &espServerPort ) ) { // "save" the ESP server's address and port in case we need to connect as client: Str espServerAddr = espComm_->getPeerAddress(); espComm_->setEspServerAddressAndPort( espServerAddr, espServerPort ); if( debug_ ) { Str msg = Str( "Captured ESP server address and port in case we need/can " ) + "connect as client: " + espServerAddr + ":" + espServerPort; logDebug( msg ); } startState_ = SS_CONNECTED; return STARTING; } else { return STOP; // No setFailure here as it's handled in scanEspServerPort above. } } case SS_CONNECTED: { // ready to start the overall sampling phase: espReady(); return startSamplingPhase(); } default: logger_.syslog( Str( "invalid startState_=" ) + startState_ + ". please report this bug.", Syslog::ERROR ); } return STARTING; // should never get here. } Component::RunState ESPComponent::waitForESPConnection() { if( startTimeAccept_.elapsed() < poTimeout_ ) { if( debug_ ) { logDebug( "ESPComponent: waiting for ESP to connect" ); } espComm_->acceptClient(); if( espComm_->hasError() ) { if( espComm_->getError() == ESPComm::TIMEOUT_ACCEPT_CLIENT ) { // ok, we will retry if still within timeout after next call return STARTING; } else { // some actual error logger_.syslog( "Error while waiting for ESP connection", Syslog::FAULT ); return STOP; } } return STARTING; } else { // actual timeout logger_.syslog( "Timeout while waiting for ESP to connect (elapsed=" + startTimeAccept_.elapsed().toString() + ")", Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); return STOP; } } int ESPComponent::getLine( Str& line ) { if( startTimeForLine_.elapsed() >= lineTimeout_ ) { logger_.syslog( "Timeout while waiting for line", Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); return -99; // error indicator different of any from ESPComm::readLine below } char response[1024]; int len = espComm_->readLine( response, sizeof( response ) ); if( len <= -2 ) // actual error in readLine { return len; } int ret = 0; // assume still waiting for line. if( len > 0 ) // we got data { if( response[len - 1] == '\n' ) // we got a new line { // do not include trailing \n in reported line: line = partialLine_ + Str( response, len - 1 ); partialLine_ = ""; if( debug_ ) { Str escaped = espComm_->escape( line.cStr(), line.length() ); Str msg = Str( ":-<: \"" ) + escaped + "\""; logDebug( msg ); } ret = +1; // ok, we got a line } else { partialLine_ += Str( response, len ); } } // else: (len == 0 || len == -1) => still waiting for line. return ret; } void ESPComponent::espReady() { // prepare log file: const char* espLogFilename = "Logs/latest/ESP.log"; struct stat attrib; if( ::stat( "Logs/latest", &attrib ) == 0 ) { bool onlyLog = !debug_; // so, include all lines if we are in debug mode espComm_->setEspLogFile( espLogFilename, onlyLog ); } else { Str msg = Str( "ESPComponent::starting: cannot write to " ) + espLogFilename; msg += " because Logs/latest does not yet exist"; logger_.syslog( msg, Syslog::IMPORTANT ); } // construct supporting ESPClient: createESPClient(); } /// Pause for a short period (indicated by pauseTime) Component::RunState ESPComponent::pause() { // This state is not currently used if( debug_ ) logDebug( "Pause" ); return STOP; } // Should eventually follow a PAUSE request: should set continueTime Component::RunState ESPComponent::paused() { if( debug_ ) logDebug( "Paused" ); // This state is not currently used return STOP; } Component::RunState ESPComponent::resume() { if( debug_ ) logDebug( "Resume" ); return START; } Component::RunState ESPComponent::resuming() { if( debug_ ) logDebug( "Resuming" ); // This state is not currently used return START; } Component::RunState ESPComponent::runnable() { readAdjustableConfigs(); // Done if we don't want data and we're done sampling if( !isDataRequested() && !samplingActive_ ) { return STOP; } if( simulateHardware() ) { Component::RunState nextRunState; if( handleStopSamplingRequest( nextRunState ) ) { return nextRunState; } if( getSimulatedData() ) { writeData(); this->resetFailCount(); return RUNNABLE; } else if( samplingActive_ ) { return RUNNABLE; } else { return STOP; } } if( !logVoltageAndCurrent() ) { return STOP; } ESPClient::SamplingState newSamplingState = espClient_->currentSamplingState(); if( newSamplingState != samplingState_ ) { Str stateTransitionResult = espComm_->getEspStateTransitionResult(); Str stateTransitionResultMsg = stateTransitionResult.startsWith( "@" ) ? Str( " (" ) + stateTransitionResult + ")" : ""; Str msg = Str( "[sample #" ) + sampleNumber_ + Str( "] ESP sampling state: " ) + espClient_->samplingStateName( newSamplingState ) + stateTransitionResultMsg ; logger_.syslog( msg, Syslog::IMPORTANT ); if( newSamplingState == ESPClient::S_PAUSED ) { if( stateTransitionResult.startsWith( "@" ) ) { float sampleVolume = -1; int parseRes = sscanf( stateTransitionResult.cStr(), "@%f", &sampleVolume ); if( parseRes != 1 ) { Str msg = Str( "Couldn't parse sample volume from '" ) + stateTransitionResult + "'. Ignoring."; logger_.syslog( msg, Syslog::IMPORTANT ); } else { writeSampleVolume( sampleVolume ); } } } } samplingState_ = newSamplingState; bool samplingCompleted = !espClient_->isSampling(); if( samplingCompleted ) { if( !upsyncRequested_ && rsyncESPlogs() ) { upsyncTime_ = Timestamp::Now(); upsyncRequested_ = true; return RUNNABLE; } if( upsyncTime_.elapsed() > upsyncTimeout_ || upsyncTime_ == Timestamp::NOT_SET_TIME ) { if( espClient_->isSuccessfulSampling() ) { Str msg = Str( "[sample #" ) + sampleNumber_ + Str( "] ESP sampling sequence completed normally." ); logger_.syslog( msg, Syslog::IMPORTANT ); sampleTime_ = Timestamp::Now(); writeData(); this->resetFailCount(); } else { Str error = espClient_->getSamplingError(); logger_.syslog( Str( "[sample #" ) + sampleNumber_ + Str( "] ESP sampling sequence terminated with error: " ) + error, Syslog::CRITICAL ); this->setFailure( FailureMode::COMMUNICATIONS ); } upsyncTime_ = Timestamp::NOT_SET_TIME; upsyncRequested_ = false; return STOP; } else { return RUNNABLE; } } else { // check for possible request to stopSampling: if( stopSamplingReader_->asInt( Units::BOOL ) && !espClient_->stopSamplingRequested() ) { // calling this right away, although, externally, it could be somewhat misleading // to see the flag as false while the action is still being acted on. resetStopSamplingIfSet(); // If that's the case, this can be removed here as the check and reset // will be done in ::stop anyway. espClient_->stopSampling(); // this just sets an internal flag in the espClient, which will eventually // act on the request when appropriate. Str msg = Str( "[sample #" ) + sampleNumber_ + Str( "] " ) + "Stop sampling requested." ; logger_.syslog( msg, Syslog::IMPORTANT ); } return RUNNABLE; } } Component::RunState ESPComponent::stop() { if( debug_ ) logDebug( Str( "ESPComponent::stop startState_=" ) + startStateName( startState_ ) ); // were we connected? (used to actually report log summary below): const bool connected = startState_ == SS_CONNECTED; resetStopSamplingIfSet(); startState_ = SS_INIT; samplingActive_ = false; if( !simulateHardware() ) { // close espComm_ if open if( espComm_ != 0 ) { if( connected ) { reportEspLogSummary(); } if( espComm_->isReadable() ) { espComm_->close(); } // and also, *unless* the ESP is acting always as server, // make it forget the ESP host and port from any previous run: if( !espAlwaysServer_ ) { espComm_->setEspServerAddressAndPort( "", 0 ); // This in particular will "force" a regular connection sequence // in the next STARTING state, that is, basically the // "power-up + tcp-server + wait-for-the-ESP-to-connect" sequence. } } if( espClient_ != 0 ) { delete espClient_; espClient_ = 0; } if( !espAlwaysServer_ ) { powerDownESP(); } } return STOPPING; } Component::RunState ESPComponent::stopping() { if( debug_ ) logDebug( "ESPComponent::stopping" ); if( !simulateHardware() ) { if( !espAlwaysServer_ ) { // See if anything went wrong that may have caused this request for uninitialize loadControl_.readFaults(); loadControl2_.readFaults(); if( loadControl_.hasError() ) { logger_.syslog( "LCB 1 fault: " + loadControl_.errorString(), Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); } if( loadControl2_.hasError() ) { logger_.syslog( "LCB 2 fault: " + loadControl2_.errorString(), Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); } } } return STOPPED; } Component::RunState ESPComponent::stopped() { if( debug_ ) logDebug( "ESPComponent::stopped" ); if( isDataRequested() ) { return START; } return STOPPED; } bool ESPComponent::handleStopSamplingRequest( RunState &nextRunState ) { // get current run state and stopSampling flag: const RunState currentRunState = getRunState(); int stopSampling( 0 ); if( stopSamplingReader_->read( Units::BOOL, stopSampling ) && stopSampling ) { switch( currentRunState ) { case START: nextRunState = STOP; return true; case STARTING: nextRunState = STOP; return true; case RUNNABLE: // except for simulateHardware, this case is in general // already handled in the main ::runnable() body. nextRunState = STOP; return true; default: return false; } } return false; } void ESPComponent::resetStopSamplingIfSet() { int stopSampling( 0 ); if( stopSamplingReader_->read( Units::BOOL, stopSampling ) && stopSampling ) { logDebug( "Resetting stopSampling to false" ); stopSampling = 0; Timestamp timestamp = Timestamp::Now(); stopSamplingWriter_->write( Units::BOOL, stopSampling, timestamp ); } } void ESPComponent::reportEspLogSummary() { FlexArray* espLogSummaryLines = espComm_->getEspLogSummaryLines(); if( espLogSummaryLines == 0 ) return; // No ESP log summary handling. if( espLogSummaryReported_ ) return; const Service::ServiceType serviceType = Service::SERVICE_COURIER; const size_t numLines = ( int ) espLogSummaryLines->size(); if( numLines > 0 ) { Str headerLine = Str( "[sample #" ) + sampleNumber_ + Str( "] ESP log summary report (" ) + ( ( int ) numLines ) + Str( " messages):" ) + "\n"; // do the report in blocks to minimize total number of logger_.syslog calls: FlexArray blocks( true ); blocks.push( new Str( headerLine ) ); for( unsigned int i = 0; i < numLines; ++i ) { Str line = *espLogSummaryLines->get( i ) + "\n"; int currentBlockIndex = blocks.size() - 1; if( blocks[currentBlockIndex]->length() + line.length() < 65000 ) { *blocks[currentBlockIndex] += line; } else { blocks.push( new Str( line ) ); } } if( blocks.size() == 1 ) { logger_.syslog( *blocks[0], Syslog::IMPORTANT, serviceType ); } else { unsigned int numBlocks = blocks.size(); for( unsigned int blockIndex = 0; blockIndex < numBlocks; ++blockIndex ) { char headLine[256]; ::sprintf( headLine, "ESP summary: (block %d/%d)\n", blockIndex + 1, numBlocks ); logger_.syslog( Str( headLine ) + *blocks[blockIndex], Syslog::IMPORTANT, serviceType ); } } } else logger_.syslog( Str( "[sample #" ) + sampleNumber_ + Str( "] No ESP summary messages." ), Syslog::IMPORTANT, serviceType ); espLogSummaryReported_ = true; } bool ESPComponent::scanEspServerPort( Str& line, int *espServerPort ) { int port = -1; int ret = sscanf( line.cStr(), "%d", &port ); if( ret == 1 ) { if( debug_ ) logDebug( Str( "scanEspServerPort: scanned port=" ) + port ); if( port > 0 ) { *espServerPort = port; return true; } logger_.syslog( Str( "ESP indicated an invalid port number=" ) + port, Syslog::FAULT ); } else { logger_.syslog( Str( "Could not scan an integer (port number) in line from ESP" ), Syslog::FAULT ); } this->setFailure( FailureMode::COMMUNICATIONS ); return false; } void ESPComponent::createESPClient() { if( espClient_ != 0 ) { logger_.syslog( "WARN: espClient_ expected to be null in createESPClient. please report this bug", Syslog::ERROR ); delete espClient_; } espClient_ = new ESPClient( *espComm_, logger_, initialPromptTimeout_, loadCartridgeTimeout_, filterResultTimeout_, processResultTimeout_, stopResultTimeout_ ); espClient_->setDebug( debug_ ); } Component::RunState ESPComponent::startSamplingPhase() { if( debug_ ) logDebug( "startSamplingPhase" ); sampleNumber_ += 1; // get cartridge argument, if any: Str cartridge = ""; Str cartridgeLogMsg; if( cartridgeArgumentReader_->isActive() ) { cartridge = cartridgeArgumentReader_->asString( Units::NONE ); cartridgeLogMsg = Str( "Setting cartridge argument to " ) + cartridge; } else { cartridgeLogMsg = Str( "Explicit cartridge argument not given" ); } logger_.syslog( Str( "[sample #" ) + sampleNumber_ + Str( "] " ) + cartridgeLogMsg, Syslog::IMPORTANT ); bool startedSampling = espClient_->startSampling( cartridge ); if( !startedSampling ) // problem { Str error = espClient_->getSamplingError(); logger_.syslog( Str( "[sample #" ) + sampleNumber_ + Str( "] Error starting ESP sampling sequence: " ) + error, Syslog::ERROR ); return STOP; } samplingState_ = espClient_->currentSamplingState(); Str msg = Str( "[sample #" ) + sampleNumber_ + Str( "] ESP sampling sequence starting." ) + " Sampling state: " + espClient_->samplingStateName( samplingState_ ); logger_.syslog( msg, Syslog::IMPORTANT ); sampleTime_ = Timestamp::Now(); samplingActive_ = true; // write the active writer state: // samplingActiveWriter_->write( Units::BOOL, samplingActive_, sampleTime_ ); writeData(); if( debug_ ) { logDebug( msg ); } return RUNNABLE; } bool ESPComponent::logVoltageAndCurrent() { //logDebug( "ESPComponent::logVoltageAndCurrent" ); // Log voltage and current and check for any faults if( !espAlwaysServer_ ) { loadControl_.requestVoltageAndCurrent(); loadControl2_.requestVoltageAndCurrent(); if( loadControl_.hasError() ) { logger_.syslog( "LCB 1 fault: " + loadControl_.errorString(), Syslog::FAULT ); // No fault for now as we don't want to drop power this->setFailure( FailureMode::HARDWARE ); return false; } if( loadControl2_.hasError() ) { logger_.syslog( "LCB 2 fault: " + loadControl2_.errorString(), Syslog::FAULT ); // No fault for now as we don't want to drop power this->setFailure( FailureMode::HARDWARE ); return false; } } return true; } bool ESPComponent::isDataRequested() { return samplingActiveWriter_->isDataRequested(); // return true; } bool ESPComponent::getSimulatedData() { if( !samplingActive_ ) { sampleTime_ = Timestamp::Now(); samplingActive_ = true; return true; } else if( sampleTime_.elapsed() > sampleTimeout_ - Timespan( 60 ) ) { sampleTime_ = Timestamp::Now(); samplingActive_ = false; sampleNumber_ += 1; return true; } return false; } void ESPComponent::writeSampleVolume( float sampleVolume ) { logDebug( Str( "Writing " ) + "sampleVolume=" + sampleVolume ); Timestamp timestamp = Timestamp::Now(); sampleVolumeWriter_->write( Units::MILLILITER, sampleVolume, timestamp ); } void ESPComponent::writeData() { logDebug( Str( "Writing " ) + "samplingActive=" + samplingActive_ + ", sampleNumber=" + sampleNumber_ ); samplingActiveWriter_->write( Units::BOOL, samplingActive_, sampleTime_ ); sampleNumberWriter_->write( Units::COUNT, sampleNumber_, sampleTime_ ); } // This duplicated stop() for now so that quit will call it void ESPComponent::uninitialize() { if( !simulateHardware() ) { if( !espAlwaysServer_ && !loadControl_.powerDown() ) { logger_.syslog( "Failed to power down", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); } // TODO review proper action here depending on concrete uninitialize semantics if( espComm_ != 0 ) espComm_->close(); // Power off secondary supply if( !espAlwaysServer_ && !loadControl2_.powerDown() ) { logger_.syslog( "Failed to power down secondary", Syslog::FAULT ); this->setFailure( FailureMode::HARDWARE ); } } } void ESPComponent::startPPP( void ) { // Enable xceiver uart_.enableUART(); // Create the command string to start PPPD pppCmd_ = "/sbin/pppd " + pppFlow_.asString() + " " + uartName_.asString() + " " + connectExec_.asString(); logger_.syslog( "Starting PPPD with command:" + Str( pppCmd_.cStr() ), Syslog::IMPORTANT ); FILE *p( popen( pppCmd_.cStr(), "r" ) ); if( NULL == p ) { logger_.syslog( "Cannot start PPPD: " + Str( pppCmd_.cStr() ), Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); } else pclose( p ); } void ESPComponent::stopPPP( void ) { FILE *p( popen( "killall pppd", "r" ) ); if( NULL == p ) { logger_.syslog( "Cannot stop PPPD.", Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); } else pclose( p ); // Disable xceiver uart_.disableUART(); } bool ESPComponent::rsyncESPlogs( void ) { bool ok( false ); StrValue ESPupsync; if( Slate::ReadOnce( ESPComponentIF::UPSYNC_CFG, ESPupsync, logger_ ) ) { Str upsyncCmd = ESPupsync.asString() + " &"; logger_.syslog( "Syncing ESP logs with command: " + upsyncCmd, Syslog::IMPORTANT ); // Issue ESP file sync command FILE *p( popen( upsyncCmd.cStr(), "r" ) ); if( NULL == p ) { logger_.syslog( "Failed to start ESP logs sync.", Syslog::FAULT ); this->setFailure( FailureMode::COMMUNICATIONS ); upsyncTime_ = Timestamp::NOT_SET_TIME; } else { logger_.syslog( "closing pipe.", Syslog::INFO ); pclose( p ); ok = true; } } return ok; } bool ESPComponent::readConfigs() { // TETHYS-612. TODO read this from config when lrauv-config/pull-requests/6 is merged poRetryWait_ = Timespan( 10.0 ); bool ok( true ); ok &= connectTimeoutCfgReader_ ->read( connectTimeout_ ); ok &= debugCfgReader_ ->read( debug_ ); ok &= espLogFilterRegexReader_ ->read( espLogFilterRegexStr_ ); ok &= espServerHostCfgReader_ ->read( espServerHost_ ); ok &= filterResultTimeoutCfgReader_ ->read( filterResultTimeout_ ); ok &= initialPromptTimeoutCfgReader_ ->read( initialPromptTimeout_ ); ok &= loadCartridgeTimeoutCfgReader_ ->read( loadCartridgeTimeout_ ); ok &= poTimeoutCfgReader_ ->read( poTimeout_ ); ok &= processResultTimeoutCfgReader_ ->read( processResultTimeout_ ); ok &= sampleTimeoutCfgReader_ ->read( sampleTimeout_ ); ok &= socketServerPortCfgReader_ ->read( Units::COUNT, socketServerPort_ ); ok &= stopResultTimeoutCfgReader_ ->read( stopResultTimeout_ ); ok &= upsyncTimeoutCfgReader_ ->read( upsyncTimeout_ ); return ok; } bool ESPComponent::readAdjustableConfigs() { bool ok( true ); ok &= sampleTimeoutCfgReader_ ->read( sampleTimeout_ ); return ok; } void ESPComponent::logDebug( Str msg ) { logger_.syslog( msg, Syslog::DEBUG ); // printf( "ESPComponent: DEBUG: %s\n", msg.cStr() ); } /// Should return [myNamespace]::SIMULATE_HARDWARE, or [myNamespace]::POWER, etc ConfigURI ESPComponent::getConfigURI( ConfigOption configOption ) const { switch( configOption ) { case CONFIG_POWER: return ESPComponentIF::POWER; case CONFIG_SIMULATE_HARDWARE: return ESPComponentIF::SIMULATE_HARDWARE; default: return ConfigURI::NO_CONFIG_URI; } }