Move VariableServerSession logs into subdirectory; make separate toggle for session logs

docs/documentation/simulation_capabilities/Status-Message-System.md

@@ -14,9 +14,9 @@ If there are no subscribers, then publishing a message has no effect.
 ## Message Subscriber
 
 There can be any number of Message Subscribers, whose job is to receive (and usually output) published messages. Trick automatically creates three Message Subscribers:
-- `Trick::MessageCout` - outputs messages to the standard output stream
-- `Trick::MessageFile` - outputs messages to a file named `send_hs` in the RUN directory
-- `Trick::MessageTCDevice` - outputs messages to a socket at port 7200, used by the Simulation Control Panel for its Status Messages display
+- `Trick::MessageCout` - outputs messages with level < 100 to the standard output stream
+- `Trick::MessageHSFile` - outputs messages with level < 100 to a file named `send_hs` in the RUN directory
+- `Trick::MessageTCDevice` - outputs messages with level < 100 to a socket at port 7200, used by the Simulation Control Panel for its Status Messages display
 
 When you publish a message, it will be output by the three subscribers above.
 A subscriber can be enabled / disabled at any time during simulation execution to output / ignore messages as desired.
@@ -33,16 +33,18 @@ trick_message.mtcout.init()
 trick.message_subscribe(trick_message.mtcout)
 ```
 
-## User accessible routines
+## Publish a message
 
 To publish a message:
 
 ```cpp
-int ::message_publish(int level, const char * format_msg, ...) ;
-int ::send_hs(FILE * fp, const char * format_msg, ...) ;
+#include "trick/message_proto.h"
+#include "trick/message_level.h"
+
+int message_publish(int level, const char * format_msg, ...) ;
 ```
 
-The level number can be any integer from 0 to 99. Trick has a few predefined levels (`Trick::MessagePublisher::MESSAGE_TYPE`) that it uses for publishing messages.
+The level number can be any number greater than or equal to 0. Levels 0-99 are captured by Trick's default message subscribers. Trick has a few predefined levels (`Trick::MessagePublisher::MESSAGE_TYPE`) that it uses for publishing messages.
 If the message subscriber's color is enabled (see below), then a particular colored message will be displayed for each of these levels:
 - 0 - normal message, default color
 - 1 - informational message, green
@@ -50,6 +52,31 @@ If the message subscriber's color is enabled (see below), then a particular colo
 - 3 - error message, red
 - 10 - debug message, cyan
 
+## Open a custom log file
+
+To open a custom message file:
+
+```cpp
+#include "trick/Message_proto.hh"
+
+int open_custom_message_file(std::string file_name, std::string subscriber_name, int level = -1);
+```
+
+This function opens a new file, adds it to the list of message subscribers, and returns the level that can be used to write to the file.
+
+A user can specify a level >= 0. If `open_custom_message_file` is called without a level argument, the function will assign a unique level to the file that is >= 100. If a user wants the messages written to this file to also be captured by default Trick message subscribers, they should specify a level from 0-99. 
+
+Example:
+```cpp
+// Open the logfile
+int my_level = open_custom_message_file("my_log_dir/logfile", "custom_log");
+
+// Write to it by publishing a message with the given level
+message_publish(my_level, "This message will be written to my custom logfile");
+```
+
+## User accessible routines
+
 To subscribe / unsubscribe Trick's default subscribers (these call `::message_subscribe` / `::message_unsubscribe` mentioned above):
 
 By default these are all subscribed. You can use subscribe/unsubscribe throughout a simulation to turn on/off messages at will.

docs/documentation/simulation_capabilities/Variable-Server.md

@@ -39,7 +39,7 @@ int set_var_server_info_msg_on();
 ```
 
 These commands are also for toggling information messages from the variable server (i.e., commands received from <i>ALL</i> clients).
-The messages only go to a dedicated "varserver_log" file in the RUN directory.
+The messages only go to a dedicated `varserver_log` file in the RUN directory.
 The variable server log capability is off by default.
 
 ```c
@@ -47,6 +47,16 @@ int set_var_server_log_off();
 int set_var_server_log_on();
 ```
 
+These commands are also for toggling individual variable server session logs.
+Each log records the IP and port number of the client that connected and every message received.
+These logs go into a subdirectory under the RUN direcory called `sesssion_logs`, and the files are named `VSSession<num>.log`
+The variable server session log capability is off by default.
+
+```c
+int set_var_server_session_log_off();
+int set_var_server_session_log_on();
+```
+
 ### Getting and Setting the Variable Server Port Information
 
 To set the variable server port to a fixed number in the input file use var_server_set_port()

include/trick/CommandLineArguments.hh

@@ -139,6 +139,7 @@ namespace Trick {
             */
             void set_output_dir(std::string output_directory) ;
 
+            // TODO: Move elsewhere
             // Helper method to create full path
             static int create_path(const std::string& dirname);
 

include/trick/MessageCustomFile.hh

@@ -39,17 +39,17 @@ namespace Trick {
              * @brief Get the level
              * 
              */
-            virtual int get_level();
+            virtual int get_level() const;
+            virtual void set_level(int level);
 
             virtual void set_name(std::string name);
             virtual void set_file_name(std::string file_name);
 
-            int this_level;
 
         protected:
+            int _this_level;
 
             static int level_counter;
-            // static std::vector<MessageCustomFile *>& all_instances();
 
 
     } ;

include/trick/MessageCustomManager.hh

@@ -44,7 +44,7 @@ namespace Trick {
             int restart();
 
         protected:
-            std::vector<MessageCustomFile *> custom_message_files;
+            std::vector<MessageCustomFile *> _custom_message_files;
     } ;
 
 }

include/trick/Mock/MockVariableServerSession.hh

@@ -13,8 +13,8 @@ class MockVariableServerSession : public Trick::VariableServerSession {
         MOCK_CONST_METHOD0(get_enabled, bool());
         MOCK_CONST_METHOD0(get_write_mode, VS_WRITE_MODE());
         MOCK_CONST_METHOD0(get_copy_mode, VS_COPY_MODE());
-        MOCK_METHOD0(set_log_on, int());
-        MOCK_METHOD0(set_log_off, int());
+        MOCK_METHOD1(set_log, int(bool on_off));
+        MOCK_METHOD1(set_session_log, int(bool on_off));
         MOCK_METHOD0(copy_sim_data, int());
         MOCK_CONST_METHOD0(get_update_rate, double());
         MOCK_CONST_METHOD0(get_frame_multiple, int());

include/trick/VariableServer.hh

@@ -174,6 +174,11 @@ namespace Trick {
             */
             bool get_log() ;
 
+            /**
+             @brief @userdesc Test if the variable server logging is on.
+            */
+            bool get_session_log() ;
+
             /**
              @brief @userdesc Command to turn on variable server info messages (e.g., get a message
               when a command is received from any client).
@@ -213,6 +218,24 @@ namespace Trick {
             */
             void set_var_server_log_off() ;
 
+                        /**
+             @brief @userdesc Command to turn on variable server session logging for all clients.
+             Each new session will create a file under RUN_<>/session_logs/ containg the client's IP and port and all messages received.
+             @par Python Usage:
+             @code trick.set_var_server_log_on() @endcode
+             @return always 0
+            */
+            void set_var_server_session_log_on() ;
+
+            /**
+             @brief @userdesc Command to turn off variable server session logging for all clients.
+             No session log will be creeated.
+             @par Python Usage:
+             @code trick.set_var_server_log_off() @endcode
+             @return always 0
+            */
+            void set_var_server_session_log_off() ;
+
             /**
              @brief @userdesc Command to open additional variable server listen port.
              @param source_address - the name or numeric IP of the machine to bind listen socket.  NULL or empty
@@ -282,6 +305,9 @@ namespace Trick {
                 to a varserver_log file in the RUN directory.\n */
             bool log ;                       /**< trick_units(--)  */
 
+            /** Toggle to turn on/off variable server individual session logs. */
+            bool session_log ;                       /**< trick_units(--)  */
+
             /** Default listen port thread object */
             VariableServerListenThread listen_thread ;
 

include/trick/VariableServerSession.hh

@@ -343,22 +343,23 @@ namespace Trick {
         virtual int var_byteswap(bool on_off) ;
 
         /**
-         @brief @userdesc Command to turn on variable server logged messages to a playback file.
+         @brief @userdesc Command to toggle variable server logged messages to a playback file.
             All messages received from all clients will be saved to file named "playback" in the RUN directory.
             @par Python Usage:
-            @code trick.set_log_on() @endcode
+            @code trick.set_log(<on_off>) @endcode
             @return always 0
         */
-        virtual int set_log_on() ;
+        virtual int set_log(bool on_off) ;
 
         /**
-         @brief @userdesc Command to turn off variable server logged messages to a playback file.
+         @brief @userdesc Command to toggle variable server session log.
+            Each session will create a file containing the IP and port of client and all messages.
+            The file will be created in a session_log/ subdirectory under the RUN directory.
             @par Python Usage:
-            @code trick.set_log_off() @endcode
+            @code trick.set_session_log(<on_off>) @endcode
             @return always 0
         */
-        virtual int set_log_off() ;
-
+        virtual int set_session_log (bool on_off) ;
 
         /**
          @brief @userdesc Command to set info messages.
@@ -420,6 +421,7 @@ namespace Trick {
 
     private:
         static int instance_counter;
+        static std::string log_subdir;
 
         pthread_mutex_t _copy_mutex;     /**<  trick_io(**) */
 
@@ -452,7 +454,7 @@ namespace Trick {
         void log_received_message(const std::string& msg);
         void log_connection_opened ();
 
-        bool is_log_open();
+        bool is_session_log_open();
 
         void open_session_log();
 
@@ -509,11 +511,14 @@ namespace Trick {
         /** Toggle to turn on/off variable server logged messages to a playback file.\n */
         bool _log ;                       /**< trick_io(**)  */
 
+        /** Toggle to turn on/off individual variable server session logs.\n */
+        bool _session_log;              /**< trick_io(**)  */
+
         /** Toggle to turn on/off debug info messages.\n */
         bool _info_msg ;
 
-        /** Message stream number for the log file */
-        int _log_msg_stream;
+        /** Message stream number for the session log file */
+        int _session_log_msg_stream;
 
         /** Toggle to indicate var_pause commanded.\n */
         bool _pause_cmd ;                 /**<  trick_io(**) */

include/trick/command_line_protos.h

@@ -45,5 +45,8 @@ void set_output_dir(const char* output_directory);
 std::string & command_line_args_get_input_file_ref(void) ;
 #endif
 
+void create_path(const char* directory);
+
+
 #endif
 

trick_source/sim_services/CommandLineArguments/command_line_c_intf.cpp

@@ -114,3 +114,6 @@ std::string & command_line_args_get_input_file_ref(void) {
     return(the_cmd_args->get_input_file_ref()) ;
 }
 
+void create_path(const char* directory) {
+    Trick::CommandLineArguments::create_path(directory);
+}

trick_source/sim_services/Message/MessageCustomFile.cpp

@@ -13,7 +13,7 @@ int Trick::MessageCustomFile::level_counter = 200;
 @details
 -# Initializes everything
 */
-Trick::MessageCustomFile::MessageCustomFile() : this_level(level_counter++) {
+Trick::MessageCustomFile::MessageCustomFile() : _this_level(level_counter++) {
 }
 
 /**
@@ -23,19 +23,24 @@ Trick::MessageCustomFile::MessageCustomFile() : this_level(level_counter++) {
 -# Flush the stream
 */
 void Trick::MessageCustomFile::update( unsigned int level , std::string header, std::string message ) {
-    if ( enabled && level == this_level ) {
+    if ( enabled && level == _this_level ) {
         out_stream << header << message ;
         out_stream.flush() ;
     }
 }
 
-int Trick::MessageCustomFile::get_level() {
-    return this_level;
+int Trick::MessageCustomFile::get_level() const {
+    return _this_level;
+}
+
+void Trick::MessageCustomFile::set_level(int level) {
+    if (level >= 0)
+        _this_level = level;
 }
 
 void Trick::MessageCustomFile::set_name(std::string name) {
     if (name == "") {
-        name = "CustomLog" + this_level;
+        name = "CustomLog" + std::to_string(_this_level);
     }    
     this->name = name;
 }

trick_source/sim_services/Message/MessageCustomManager.cpp

@@ -6,7 +6,7 @@ Trick::MessageCustomManager * the_message_custom_manager ;
 
 int open_custom_message_file(std::string file_name, std::string subscriber_name, int level) {
     if (the_message_custom_manager == NULL) {
-        std::cout << "Problem: custom_message_manager not yet intantiated" << std::endl;
+        std::cout << "Problem: custom_message_manager not yet instantiated" << std::endl;
         return -1;
     }
 
@@ -23,7 +23,7 @@ Trick::MessageCustomManager::MessageCustomManager() {
 Trick::MessageCustomManager::~MessageCustomManager() {
     the_message_custom_manager = NULL;
     
-    for (Trick::MessageCustomFile *  message_file : custom_message_files) {
+    for (Trick::MessageCustomFile *  message_file : _custom_message_files) {
         TMM_delete_var_a(message_file);
     }
 }
@@ -31,11 +31,12 @@ Trick::MessageCustomManager::~MessageCustomManager() {
 int Trick::MessageCustomManager::open_custom_message_file(std::string file_name, std::string subscriber_name, int level) {
     Trick::MessageCustomFile * new_message_file = (Trick::MessageCustomFile *) TMM_declare_var_s("Trick::MessageCustomFile");
 
+    new_message_file->set_level(level);
     new_message_file->set_file_name(file_name);
     new_message_file->set_name(subscriber_name);
     new_message_file->init();
 
-    custom_message_files.push_back(new_message_file);
+    _custom_message_files.push_back(new_message_file);
 
     return new_message_file->get_level();
 }
@@ -44,13 +45,13 @@ int Trick::MessageCustomManager::open_custom_message_file(std::string file_name,
  @brief Output message to the file.
     */
 void Trick::MessageCustomManager::update( unsigned int level , std::string header , std::string message ) {
-    for (MessageCustomFile* message_file : custom_message_files) {
+    for (auto message_file : _custom_message_files) {
         message_file->update(level, header, message);
     }
 }
 
 int Trick::MessageCustomManager::restart( ) {
-    for (MessageCustomFile* message_file : custom_message_files) {
+    for (auto message_file : _custom_message_files) {
         message_file->restart();
     }
 

trick_source/sim_services/Message/MessageFile.cpp

@@ -1,9 +1,14 @@
 
 #include <iostream>
 #include <unistd.h>
+#include <string>
 
 #include "trick/MessageFile.hh"
 #include "trick/command_line_protos.h"
+#include "trick/message_proto.h"
+#include "trick/message_type.h"
+
+
 
 /**
 @details
@@ -48,7 +53,18 @@ void Trick::MessageFile::update( unsigned int level , std::string header, std::s
 int Trick::MessageFile::init() {
 
     unlink((std::string(command_line_args_get_output_dir()) + "/" + file_name).c_str()) ;
+
+    // Create the directory if we need to
+    int pos = file_name.find_last_of("/");
+    if (pos != std::string::npos) {
+        std::string dir = std::string(command_line_args_get_output_dir()) + "/" + file_name.substr(0, pos);
+        create_path(dir.c_str());
+    }
+
     out_stream.open((std::string(command_line_args_get_output_dir()) + "/" + file_name).c_str() , std::fstream::out | std::fstream::app ) ;
+    if (!out_stream.is_open()) {
+        message_publish(MSG_ERROR, "Failed to open message file %s\n",file_name.c_str());
+    }
     return(0) ;
 }
 

trick_source/sim_services/VariableServer/VariableServer.cpp

@@ -69,11 +69,15 @@ bool Trick::VariableServer::get_log() {
     return log ;
 }
 
+bool Trick::VariableServer::get_session_log() {
+    return session_log ;
+}
+
 void Trick::VariableServer::set_var_server_log_on() {
     log = true;
     // turn log on for all current vs clients
     for ( auto& session_it : var_server_sessions ) {
-        session_it.second->set_log_on();
+        session_it.second->set_log(true);
     }
 }
 
@@ -81,7 +85,23 @@ void Trick::VariableServer::set_var_server_log_off() {
     log = false;
     // turn log off for all current vs clients
     for ( auto& session_it : var_server_sessions ) {
-        session_it.second->set_log_off();
+        session_it.second->set_log(false);
+    }
+}
+
+void Trick::VariableServer::set_var_server_session_log_on() {
+    session_log = true;
+    // turn log on for all current vs clients
+    for ( auto& session_it : var_server_sessions ) {
+        session_it.second->set_session_log(true);
+    }
+}
+
+void Trick::VariableServer::set_var_server_session_log_off() {
+    session_log = false;
+    // turn log off for all current vs clients
+    for ( auto& session_it : var_server_sessions ) {
+        session_it.second->set_session_log(false);
     }
 }
 

trick_source/sim_services/VariableServer/VariableServerSession.cpp

@@ -7,12 +7,14 @@
 #include "trick/realtimesync_proto.h"
 
 int Trick::VariableServerSession::instance_counter = 0;
+std::string Trick::VariableServerSession::log_subdir = "session_logs";
 
 Trick::VariableServerSession::VariableServerSession() {
     _debug = 0;
     _enabled = true ;
     _log = false ;
-    _log_msg_stream = -1;
+    _session_log = false;
+    _session_log_msg_stream = -1;
     _info_msg = false;
     _copy_mode = VS_COPY_ASYNC ;
     _write_mode = VS_WRITE_ASYNC ;
@@ -56,25 +58,25 @@ void Trick::VariableServerSession::set_connection(ClientConnection * conn) {
     log_connection_opened();
 }
 
-bool Trick::VariableServerSession::is_log_open() {
-    return _log_msg_stream != -1;
+bool Trick::VariableServerSession::is_session_log_open() {
+    return _session_log_msg_stream != -1;
 }
 
 void Trick::VariableServerSession::open_session_log() {
     std::string name = "VSSession" + std::to_string(_instance_num);
-    _log_msg_stream = open_custom_message_file(name + ".log", name);
+    _session_log_msg_stream = open_custom_message_file(log_subdir + "/" + name + ".log", name);
 }
 
 
 // Command to turn on log to varserver_log file
-int Trick::VariableServerSession::set_log_on() {
-    _log = true;
+int Trick::VariableServerSession::set_log(bool on_off) {
+    _log = on_off;
     return(0) ;
 }
 
-// Command to turn off log to varserver_log file
-int Trick::VariableServerSession::set_log_off() {
-    _log = false;
+// Command to turn on individual session log file
+int Trick::VariableServerSession::set_session_log(bool on_off) {
+    _session_log = on_off;
     return(0) ;
 }
 
@@ -120,22 +122,25 @@ long long Trick::VariableServerSession::get_freeze_next_tics() const {
 }
 
 void Trick::VariableServerSession::log_connection_opened() {
-    if (_log) {
-        if (!is_log_open()) {
+    if (_session_log) {
+        if (!is_session_log_open()) {
             open_session_log();
         }
     
-        message_publish(_log_msg_stream, "Variable Server Session started with %s:%d\n", _connection->getClientHostname().c_str(), _connection->getClientPort());
+        message_publish(_session_log_msg_stream, "Variable Server Session started with %s:%d\n", _connection->getClientHostname().c_str(), _connection->getClientPort());
     }
 }
 
 void Trick::VariableServerSession::log_received_message(const std::string& msg) {
     if (_log) {
         message_publish(MSG_PLAYBACK, "tag=<%s> time=%f %s", _connection->getClientTag().c_str(), exec_get_sim_time(), msg.c_str());
-        
-        if (!is_log_open()) open_session_log();
+    }
 
-        message_publish(_log_msg_stream, "tag=<%s> time=%f %s", _connection->getClientTag().c_str(), exec_get_sim_time(), msg.c_str());
+    if (_session_log) {
+        if (!is_session_log_open()) 
+            open_session_log();
+
+        message_publish(_session_log_msg_stream, "tag=<%s> time=%f %s", _connection->getClientTag().c_str(), exec_get_sim_time(), msg.c_str());
     }
 
     if (_debug >= 3) {

trick_source/sim_services/VariableServer/VariableServerSessionThread_loop.cpp

@@ -41,7 +41,11 @@ void * Trick::VariableServerSessionThread::thread_body() {
 
     // if log is set on for variable server (e.g., in input file), turn log on for each client
     if (_vs->get_log()) {
-        _session->set_log_on();
+        _session->set_log(true);
+    }
+
+    if (_vs->get_session_log()) {
+        _session->set_session_log(true);
     }
 
     if (_vs->get_info_msg()) {

trick_source/sim_services/VariableServer/test/VariableServerSessionThread_test.cc

@@ -259,7 +259,7 @@ TEST_F(VariableServerSessionThread_test, turn_session_log_on) {
     varserver->set_var_server_log_on();
 
     // We expect a the session's log to be turned on
-    EXPECT_CALL(*session, set_log_on())
+    EXPECT_CALL(*session, set_log(true))
         .Times(1);
 
     // Set up VariableServerSessionThread

trick_source/sim_services/VariableServer/test/VariableServerSession_test.cc

@@ -300,7 +300,9 @@ TEST_F(VariableServerSession_test, log_on) {
     EXPECT_CALL(input_processor, parse(_));
 
     // ACT
-    session.set_log_on();
+    session.set_log(true);
+    session.set_session_log(true);
+
     session.handle_message();
 
     // ASSERT

trick_source/sim_services/VariableServer/test/VariableServer_test.cc

@@ -31,7 +31,7 @@ class VariableServer_test : public ::testing::Test {
 TEST_F(VariableServer_test, set_log_on) {
     // ARRANGE
     MockVariableServerSession session;
-    EXPECT_CALL(session, set_log_on())
+    EXPECT_CALL(session, set_log(true))
         .Times(1);
 
     pthread_t id = (pthread_t) 5;
@@ -47,7 +47,7 @@ TEST_F(VariableServer_test, set_log_on) {
 TEST_F(VariableServer_test, set_log_off) {
     // ARRANGE
     MockVariableServerSession session;
-    EXPECT_CALL(session, set_log_off())
+    EXPECT_CALL(session, set_log(false))
         .Times(1);
 
     pthread_t id = (pthread_t) 5;
@@ -60,6 +60,40 @@ TEST_F(VariableServer_test, set_log_off) {
     EXPECT_EQ(vs.get_log(), false);
 }
 
+
+TEST_F(VariableServer_test, set_session_log_on) {
+    // ARRANGE
+    MockVariableServerSession session;
+    EXPECT_CALL(session, set_session_log(true))
+        .Times(1);
+
+    pthread_t id = (pthread_t) 5;
+    vs.add_session(id, &session);
+
+    // ACT
+    vs.set_var_server_session_log_on();
+
+    // ASSERT
+    EXPECT_EQ(vs.get_session_log(), true);
+}
+
+TEST_F(VariableServer_test, set_session_log_off) {
+    // ARRANGE
+    MockVariableServerSession session;
+    EXPECT_CALL(session, set_session_log(false))
+        .Times(1);
+
+    pthread_t id = (pthread_t) 5;
+    vs.add_session(id, &session);
+
+    // ACT
+    vs.set_var_server_session_log_off();
+
+    // ASSERT
+    EXPECT_EQ(vs.get_session_log(), false);
+}
+
+
 TEST_F(VariableServer_test, enabled_by_default) {
     // ARRANGE
     // ACT

trick_source/sim_services/VariableServer/var_server_ext.cpp

@@ -358,7 +358,7 @@ Trick::VariableServerSession * session = get_session();
 int var_server_log_on() {
 Trick::VariableServerSession * session = get_session();
     if (session != NULL ) {
-        return session->set_log_on() ;
+        return session->set_log(true) ;
     }
     return 0 ;
 }
@@ -367,7 +367,25 @@ Trick::VariableServerSession * session = get_session();
 int var_server_log_off() {
 Trick::VariableServerSession * session = get_session();
     if (session != NULL ) {
-        return session->set_log_off() ;
+        return session->set_log(false) ;
+    }
+    return 0 ;
+}
+
+// Command to turn on log to playback file
+int var_server_session_log_on() {
+Trick::VariableServerSession * session = get_session();
+    if (session != NULL ) {
+        return session->set_session_log(true) ;
+    }
+    return 0 ;
+}
+
+// Command to turn off log to playback file
+int var_server_session_log_off() {
+Trick::VariableServerSession * session = get_session();
+    if (session != NULL ) {
+        return session->set_session_log(false) ;
     }
     return 0 ;
 }