Change the connected time from time_t to timespec.
authorSteinar H. Gunderson <sgunderson@bigfoot.com>
Tue, 21 Jul 2015 23:08:00 +0000 (01:08 +0200)
committerSteinar H. Gunderson <sgunderson@bigfoot.com>
Tue, 21 Jul 2015 23:08:00 +0000 (01:08 +0200)
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.

accesslog.cpp
client.cpp
client.h
state.proto
stats.cpp

index 9cd5be0..4414650 100644 (file)
@@ -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
index b226d5e..e7a12f6 100644 (file)
@@ -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);
index d23b860..4e80031 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;
index e612831..30b63da 100644 (file)
@@ -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;
index 69bbd73..b0765ed 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));