Change the connected time from time_t to timespec.

The primary gain as the code stands is that we become immune to
issues with the clock going backwards etc. in logs (since we can
now use a monotonic timer).

However, the motivating change is that we will soon be implementing request
read timeouts. At that point, not only will the clock data be much more
important to get right, but it will also be nice to have more fine-grained
timestamps to be able to locate clients semi-uniquely in a sorted list.

diff --git a/accesslog.cpp b/accesslog.cpp
index 9cd5be0ad7735cc30fe8769adada8d3509f8a079..44146504d050395e979826cde015eb7bd4b4b5bf 100644 (file)
--- a/accesslog.cpp
+++ b/accesslog.cpp
@@ -53,18 +53,22 @@ void AccessLogThread::do_work()
 
                if (logfp != NULL) {
                        // Do the actual writes.
-                       time_t now = time(NULL);
-                       for (size_t i = 0; i < writes.size(); ++i) {
-                               fprintf(logfp, "%llu %s %s %d %llu %llu %llu\n",
-                                       (long long unsigned)(writes[i].connect_time),
-                                       writes[i].remote_addr.c_str(),
-                                       writes[i].url.c_str(),
-                                       int(now - writes[i].connect_time),
-                                       (long long unsigned)(writes[i].bytes_sent),
-                                       (long long unsigned)(writes[i].bytes_lost),
-                                       (long long unsigned)(writes[i].num_loss_events));
+                       timespec now;
+                       if (clock_gettime(CLOCK_MONOTONIC_COARSE, &now) == -1) {
+                               log_perror("clock_gettime(CLOCK_MONOTONIC_COARSE)");
+                       } else {
+                               for (size_t i = 0; i < writes.size(); ++i) {
+                                       fprintf(logfp, "%llu %s %s %d %llu %llu %llu\n",
+                                               (long long unsigned)(writes[i].connect_time.tv_sec),
+                                               writes[i].remote_addr.c_str(),
+                                               writes[i].url.c_str(),
+                                               int(now.tv_sec - writes[i].connect_time.tv_sec),  // Rather coarse.
+                                               (long long unsigned)(writes[i].bytes_sent),
+                                               (long long unsigned)(writes[i].bytes_lost),
+                                               (long long unsigned)(writes[i].num_loss_events));
+                               }
+                               fflush(logfp);
                        }
-                       fflush(logfp);
                }
 
                // Wait until we are being woken up, either to quit or because

diff --git a/client.cpp b/client.cpp
index b226d5e3fb916478f9dd5edb94cadb358d9c0dd1..e7a12f6c8ef395691f3dfa86efc12d2fda228efe 100644 (file)
--- a/client.cpp
+++ b/client.cpp
@@ -16,7 +16,6 @@ using namespace std;
 
 Client::Client(int sock)
        : sock(sock),
-         connect_time(time(NULL)),
          state(Client::READING_REQUEST),
          stream(NULL),
          header_or_error_bytes_sent(0),
@@ -27,6 +26,11 @@ Client::Client(int sock)
 {
        request.reserve(1024);
 
+       if (clock_gettime(CLOCK_MONOTONIC_COARSE, &connect_time) == -1) {
+               log_perror("clock_gettime(CLOCK_MONOTONIC_COARSE)");
+               return;
+       }
+
        // Find the remote address, and convert it to ASCII.
        sockaddr_in6 addr;
        socklen_t addr_len = sizeof(addr);
@@ -59,7 +63,6 @@ Client::Client(int sock)
 Client::Client(const ClientProto &serialized, Stream *stream)
        : sock(serialized.sock()),
          remote_addr(serialized.remote_addr()),
-         connect_time(serialized.connect_time()),
          state(State(serialized.state())),
          request(serialized.request()),
          url(serialized.url()),
@@ -78,6 +81,17 @@ Client::Client(const ClientProto &serialized, Stream *stream)
                        }
                }
        }
+       if (serialized.has_connect_time_old()) {
+               // Do a rough conversion from time() to monotonic time.
+               if (clock_gettime(CLOCK_MONOTONIC_COARSE, &connect_time) == -1) {
+                       log_perror("clock_gettime(CLOCK_MONOTONIC_COARSE)");
+                       return;
+               }
+               connect_time.tv_sec += serialized.connect_time_old() - time(NULL);
+       } else {
+               connect_time.tv_sec = serialized.connect_time_sec();
+               connect_time.tv_nsec = serialized.connect_time_nsec();
+       }
 }
 
 ClientProto Client::serialize() const
@@ -85,7 +99,8 @@ ClientProto Client::serialize() const
        ClientProto serialized;
        serialized.set_sock(sock);
        serialized.set_remote_addr(remote_addr);
-       serialized.set_connect_time(connect_time);
+       serialized.set_connect_time_sec(connect_time.tv_sec);
+       serialized.set_connect_time_nsec(connect_time.tv_nsec);
        serialized.set_state(state);
        serialized.set_request(request);
        serialized.set_url(url);

diff --git a/client.h b/client.h
index d23b860767e16ecc372ab5726c6df8f2044ae7e3..4e8003110b11c04e20b5a713f44b75cff294133a 100644 (file)
--- a/client.h
+++ b/client.h
@@ -15,7 +15,7 @@ struct ClientStats {
        std::string url;
        int sock;
        std::string remote_addr;
-       time_t connect_time;
+       timespec connect_time;
        size_t bytes_sent;
        size_t bytes_lost;
        size_t num_loss_events;
@@ -33,9 +33,11 @@ struct Client {
        // The file descriptor associated with this socket.
        int sock;
 
+       // When the client connected, in terms of CLOCK_MONOTONIC_COARSE.
+       timespec connect_time;
+
        // Some information only used for logging.
        std::string remote_addr;
-       time_t connect_time;
 
        enum State { READING_REQUEST, SENDING_HEADER, SENDING_DATA, SENDING_ERROR, WAITING_FOR_KEYFRAME, PREBUFFERING };
        State state;

diff --git a/state.proto b/state.proto
index e612831e1179df8298d0703adfa5479a35ad2903..30b63da7759b4df0cc5a4c13c5802af6e6b1f771 100644 (file)
--- a/state.proto
+++ b/state.proto
@@ -2,7 +2,9 @@
 message ClientProto {
        optional int32 sock = 1;
        optional string remote_addr = 8;
-       optional int64 connect_time = 9;
+       optional int64 connect_time_old = 9;  // Contains a time_t from time(). For versions prior to 1.1.3.
+       optional int64 connect_time_sec = 13;
+       optional int32 connect_time_nsec = 14;
        optional int32 state = 2;
        optional bytes request = 3;
        optional string url = 4;

diff --git a/stats.cpp b/stats.cpp
index 69bbd732b634a4d0daebfed771401335317bf0f2..b0765ed32a4e22a0b0059144f3bd7ce321c3ccdd 100644 (file)
--- a/stats.cpp
+++ b/stats.cpp
@@ -27,12 +27,18 @@ void StatsThread::do_work()
 {
        while (!should_stop()) {
                int fd;
+               char *filename;
                FILE *fp;
-               time_t now;
+               timespec now;
                vector<ClientStats> client_stats;
 
+               if (clock_gettime(CLOCK_MONOTONIC_COARSE, &now) == -1) {
+                       log_perror("clock_gettime(CLOCK_MONOTONIC_COARSE)");
+                       goto sleep;
+               }
+
                // Open a new, temporary file.
-               char *filename = strdup((stats_file + ".new.XXXXXX").c_str());
+               filename = strdup((stats_file + ".new.XXXXXX").c_str());
                fd = mkostemp(filename, O_WRONLY);
                if (fd == -1) {
                        log_perror(filename);
@@ -51,7 +57,6 @@ void StatsThread::do_work()
                        goto sleep;
                }
 
-               now = time(NULL);
                client_stats = servers->get_client_stats();
                for (size_t i = 0; i < client_stats.size(); ++i) {
                        fprintf(fp, "%s %d %d %s %d %llu %llu %llu\n",
@@ -59,7 +64,7 @@ void StatsThread::do_work()
                                client_stats[i].sock,
                                0,  // Used to be fwmark.
                                client_stats[i].url.c_str(),
-                               int(now - client_stats[i].connect_time),
+                               int(now.tv_sec - client_stats[i].connect_time.tv_sec),  // Rather coarse.
                                (long long unsigned)(client_stats[i].bytes_sent),
                                (long long unsigned)(client_stats[i].bytes_lost),
                                (long long unsigned)(client_stats[i].num_loss_events));