Monotonic timeout (#691)

* improve a log message

* use monotonic clock for securechannel and session timeouts (#688)

src/server/ua_securechannel_manager.c

@@ -35,15 +35,15 @@ static void removeSecureChannel(UA_SecureChannelManager *cm, channel_list_entry
     UA_Server_delayedFree(cm->server, entry);
 #endif
 }
+
 /* remove channels that were not renewed or who have no connection attached */
-void UA_SecureChannelManager_cleanupTimedOut(UA_SecureChannelManager *cm, UA_DateTime now) {
+void UA_SecureChannelManager_cleanupTimedOut(UA_SecureChannelManager *cm, UA_DateTime nowMonotonic) {
     channel_list_entry *entry, *temp;
     LIST_FOREACH_SAFE(entry, &cm->channels, pointers, temp) {
-        UA_DateTime timeout =
-            entry->channel.securityToken.createdAt +
+        UA_DateTime timeout = entry->channel.securityToken.createdAt +
             (UA_DateTime)(entry->channel.securityToken.revisedLifetime * UA_MSEC_TO_DATETIME);
-        if(timeout < now || !entry->channel.connection) {
-            UA_LOG_DEBUG_CHANNEL(cm->server->config.logger, (&entry->channel), "SecureChannel has timed out");
+        if(timeout < nowMonotonic || !entry->channel.connection) {
+            UA_LOG_DEBUG_CHANNEL(cm->server->config.logger, &entry->channel, "SecureChannel has timed out");
             removeSecureChannel(cm, entry);
         } else if(entry->channel.nextSecurityToken.tokenId > 0) {
             UA_SecureChannel_revolveTokens(&entry->channel);
@@ -56,7 +56,8 @@ static UA_Boolean purgeFirstChannelWithoutSession(UA_SecureChannelManager *cm) {
     channel_list_entry *entry;
     LIST_FOREACH(entry, &cm->channels, pointers) {
         if(LIST_EMPTY(&(entry->channel.sessions))){
-            UA_LOG_DEBUG_CHANNEL(cm->server->config.logger, (&entry->channel), "Channel was purged since maxSecureChannels was reached and channel had no session attached");
+            UA_LOG_DEBUG_CHANNEL(cm->server->config.logger, &entry->channel,
+                                 "Channel was purged since maxSecureChannels was reached and channel had no session attached");
             removeSecureChannel(cm, entry);
             UA_assert(entry != LIST_FIRST(&cm->channels));
             return true;
@@ -71,46 +72,47 @@ UA_SecureChannelManager_open(UA_SecureChannelManager *cm, UA_Connection *conn,
                              UA_OpenSecureChannelResponse *response) {
     if(request->securityMode != UA_MESSAGESECURITYMODE_NONE)
         return UA_STATUSCODE_BADSECURITYMODEREJECTED;
+
     //check if there exists a free SC, otherwise try to purge one SC without a session
     //the purge has been introduced to pass CTT, it is not clear what strategy is expected here
     if(cm->currentChannelCount >= cm->server->config.maxSecureChannels && !purgeFirstChannelWithoutSession(cm)){
         return UA_STATUSCODE_BADOUTOFMEMORY;
     }
+
+    /* Set up the channel */
     channel_list_entry *entry = UA_malloc(sizeof(channel_list_entry));
     if(!entry)
         return UA_STATUSCODE_BADOUTOFMEMORY;
-#ifndef UA_ENABLE_MULTITHREADING
-    cm->currentChannelCount++;
-#else
-    cm->currentChannelCount = uatomic_add_return(&cm->currentChannelCount, 1);
-#endif
-
     UA_SecureChannel_init(&entry->channel);
-    response->responseHeader.stringTableSize = 0;
-    response->responseHeader.timestamp = UA_DateTime_now();
-    response->serverProtocolVersion = 0;
-
     entry->channel.securityToken.channelId = cm->lastChannelId++;
     entry->channel.securityToken.tokenId = cm->lastTokenId++;
     entry->channel.securityToken.createdAt = UA_DateTime_now();
     entry->channel.securityToken.revisedLifetime =
         (request->requestedLifetime > cm->server->config.maxSecurityTokenLifetime) ?
         cm->server->config.maxSecurityTokenLifetime : request->requestedLifetime;
-    /* lifetime 0 -> set the maximum possible */
-    if(entry->channel.securityToken.revisedLifetime == 0)
+    if(entry->channel.securityToken.revisedLifetime == 0) /* lifetime 0 -> set the maximum possible */
         entry->channel.securityToken.revisedLifetime = cm->server->config.maxSecurityTokenLifetime;
-
     UA_ByteString_copy(&request->clientNonce, &entry->channel.clientNonce);
-    entry->channel.serverAsymAlgSettings.securityPolicyUri = UA_STRING_ALLOC(
-            "http://opcfoundation.org/UA/SecurityPolicy#None");
-
+    entry->channel.serverAsymAlgSettings.securityPolicyUri =
+        UA_STRING_ALLOC("http://opcfoundation.org/UA/SecurityPolicy#None");
     UA_SecureChannel_generateNonce(&entry->channel.serverNonce);
+
+    /* Set the response */
     UA_ByteString_copy(&entry->channel.serverNonce, &response->serverNonce);
-    UA_ChannelSecurityToken_copy(&entry->channel.securityToken,
-            &response->securityToken);
+    UA_ChannelSecurityToken_copy(&entry->channel.securityToken, &response->securityToken);
+    response->responseHeader.timestamp = UA_DateTime_now();
 
+    /* Now overwrite the creation date with the internal monotonic clock */
+    entry->channel.securityToken.createdAt = UA_DateTime_nowMonotonic();
+
+    /* Set all the pointers internally */
     UA_Connection_attachSecureChannel(conn, &entry->channel);
     LIST_INSERT_HEAD(&cm->channels, entry, pointers);
+#ifndef UA_ENABLE_MULTITHREADING
+    cm->currentChannelCount++;
+#else
+    cm->currentChannelCount = uatomic_add_return(&cm->currentChannelCount, 1);
+#endif
     return UA_STATUSCODE_GOOD;
 }
 
@@ -130,17 +132,22 @@ UA_SecureChannelManager_renew(UA_SecureChannelManager *cm, UA_Connection *conn,
         channel->nextSecurityToken.revisedLifetime =
             (request->requestedLifetime > cm->server->config.maxSecurityTokenLifetime) ?
             cm->server->config.maxSecurityTokenLifetime : request->requestedLifetime;
-        /* lifetime 0 -> return the max lifetime */
-        if(channel->nextSecurityToken.revisedLifetime == 0)
+        if(channel->nextSecurityToken.revisedLifetime == 0) /* lifetime 0 -> return the max lifetime */
             channel->nextSecurityToken.revisedLifetime = cm->server->config.maxSecurityTokenLifetime;
     }
 
+    /* invalidate the old nonce */
     if(channel->clientNonce.data)
         UA_ByteString_deleteMembers(&channel->clientNonce);
 
+    /* set the response */
     UA_ByteString_copy(&request->clientNonce, &channel->clientNonce);
     UA_ByteString_copy(&channel->serverNonce, &response->serverNonce);
     UA_ChannelSecurityToken_copy(&channel->nextSecurityToken, &response->securityToken);
+
+    /* reset the creation date to the monotonic clock */
+    channel->nextSecurityToken.createdAt = UA_DateTime_nowMonotonic();
+
     return UA_STATUSCODE_GOOD;
 }
 

src/server/ua_securechannel_manager.h

@@ -24,7 +24,7 @@ UA_SecureChannelManager_init(UA_SecureChannelManager *cm, UA_Server *server);
 
 void UA_SecureChannelManager_deleteMembers(UA_SecureChannelManager *cm);
 
-void UA_SecureChannelManager_cleanupTimedOut(UA_SecureChannelManager *cm, UA_DateTime now);
+void UA_SecureChannelManager_cleanupTimedOut(UA_SecureChannelManager *cm, UA_DateTime nowMonotonic);
 
 UA_StatusCode
 UA_SecureChannelManager_open(UA_SecureChannelManager *cm, UA_Connection *conn,

src/server/ua_server.c

@@ -272,9 +272,9 @@ void UA_Server_delete(UA_Server *server) {
 
 /* Recurring cleanup. Removing unused and timed-out channels and sessions */
 static void UA_Server_cleanup(UA_Server *server, void *_) {
-    UA_DateTime now = UA_DateTime_now();
-    UA_SessionManager_cleanupTimedOut(&server->sessionManager, now);
-    UA_SecureChannelManager_cleanupTimedOut(&server->secureChannelManager, now);
+    UA_DateTime nowMonotonic = UA_DateTime_nowMonotonic();
+    UA_SessionManager_cleanupTimedOut(&server->sessionManager, nowMonotonic);
+    UA_SecureChannelManager_cleanupTimedOut(&server->secureChannelManager, nowMonotonic);
 }
 
 static UA_StatusCode

src/server/ua_services_session.c

@@ -50,7 +50,7 @@ void Service_CreateSession(UA_Server *server, UA_SecureChannel *channel,
 void
 Service_ActivateSession(UA_Server *server, UA_SecureChannel *channel, UA_Session *session,
                         const UA_ActivateSessionRequest *request, UA_ActivateSessionResponse *response) {
-    if(session->validTill < UA_DateTime_now()) {
+    if(session->validTill < UA_DateTime_nowMonotonic()) {
         UA_LOG_INFO_SESSION(server->config.logger, session, "ActivateSession: SecureChannel %i wants "
                             "to activate, but the session has timed out", channel->securityToken.channelId);
         response->responseHeader.serviceResult = UA_STATUSCODE_BADSESSIONIDINVALID;
@@ -61,8 +61,7 @@ Service_ActivateSession(UA_Server *server, UA_SecureChannel *channel, UA_Session
        (request->userIdentityToken.content.decoded.type != &UA_TYPES[UA_TYPES_ANONYMOUSIDENTITYTOKEN] &&
         request->userIdentityToken.content.decoded.type != &UA_TYPES[UA_TYPES_USERNAMEIDENTITYTOKEN])) {
         UA_LOG_INFO_SESSION(server->config.logger, session, "ActivateSession: SecureChannel %i wants "
-                            "to activate, but the UserIdentify token is invalid",
-                            channel->securityToken.channelId);
+                            "to activate, but the UserIdentify token is invalid", channel->securityToken.channelId);
         response->responseHeader.serviceResult = UA_STATUSCODE_BADIDENTITYTOKENINVALID;
         return;
     }

src/server/ua_session_manager.c

@@ -18,10 +18,10 @@ void UA_SessionManager_deleteMembers(UA_SessionManager *sm) {
     }
 }
 
-void UA_SessionManager_cleanupTimedOut(UA_SessionManager *sm, UA_DateTime now) {
+void UA_SessionManager_cleanupTimedOut(UA_SessionManager *sm, UA_DateTime nowMonotonic) {
     session_list_entry *sentry, *temp;
     LIST_FOREACH_SAFE(sentry, &sm->sessions, pointers, temp) {
-        if(sentry->session.validTill < now) {
+        if(sentry->session.validTill < nowMonotonic) {
             UA_LOG_DEBUG(sm->server->config.logger, UA_LOGCATEGORY_SESSION,
                          "Session with token %i has timed out and is removed",
                          sentry->session.sessionId.identifier.numeric);
@@ -43,7 +43,7 @@ UA_SessionManager_getSession(UA_SessionManager *sm, const UA_NodeId *token) {
     session_list_entry *current = NULL;
     LIST_FOREACH(current, &sm->sessions, pointers) {
         if(UA_NodeId_equal(&current->session.authenticationToken, token)) {
-            if(UA_DateTime_now() > current->session.validTill) {
+            if(UA_DateTime_nowMonotonic() > current->session.validTill) {
                 UA_LOG_DEBUG(sm->server->config.logger, UA_LOGCATEGORY_SESSION,
                              "Try to use Session with token " UA_PRINTF_GUID_FORMAT ", but has timed out",
                              UA_PRINTF_GUID_DATA((*token)));

src/server/ua_session_manager.h

@@ -22,7 +22,7 @@ UA_SessionManager_init(UA_SessionManager *sm, UA_Server *server);
 
 void UA_SessionManager_deleteMembers(UA_SessionManager *sessionManager);
 
-void UA_SessionManager_cleanupTimedOut(UA_SessionManager *sessionManager, UA_DateTime now);
+void UA_SessionManager_cleanupTimedOut(UA_SessionManager *sessionManager, UA_DateTime nowMonotonic);
 
 UA_StatusCode
 UA_SessionManager_createSession(UA_SessionManager *sessionManager, UA_SecureChannel *channel,

src/ua_session.c

@@ -69,7 +69,7 @@ void UA_Session_deleteMembersCleanup(UA_Session *session, UA_Server* server) {
 }
 
 void UA_Session_updateLifetime(UA_Session *session) {
-    session->validTill = UA_DateTime_now() + (UA_DateTime)(session->timeout * UA_MSEC_TO_DATETIME);
+    session->validTill = UA_DateTime_nowMonotonic() + (UA_DateTime)(session->timeout * UA_MSEC_TO_DATETIME);
 }
 
 #ifdef UA_ENABLE_SUBSCRIPTIONS