Rework time handling

Periodic tasks are now based on a monotonic timer. The timestamp in
the exported PCAP now corresponds to the original timestamp when using
root. Moreover, in-app first/last seen time now displays the milliseconds.

Closes #89

app/src/main/java/com/emanuelef/remote_capture/Utils.java

@@ -175,6 +175,13 @@ public class Utils {
         return fmt.format(new Date(epoch * 1000));
     }
 
+    public static String formatEpochMillis(Context context, long millis) {
+        Locale locale = getPrimaryLocale(context);
+        DateFormat fmt = new SimpleDateFormat("MM/dd/yy HH:mm:ss.SSS", locale);
+
+        return fmt.format(new Date(millis));
+    }
+
     public static String formatInteger(Context context, int val) {
         Locale locale = getPrimaryLocale(context);
         return String.format(locale, "%d", val);

app/src/main/java/com/emanuelef/remote_capture/activities/ConnectionDetailsActivity.java

@@ -193,9 +193,9 @@ public class ConnectionDetailsActivity extends BaseActivity implements Connectio
         if(conn != null) {
             mBytesView.setText(String.format(getResources().getString(R.string.rcvd_and_sent), Utils.formatBytes(conn.rcvd_bytes), Utils.formatBytes(conn.sent_bytes)));
             mPacketsView.setText(String.format(getResources().getString(R.string.rcvd_and_sent), Utils.formatPkts(conn.rcvd_pkts), Utils.formatPkts(conn.sent_pkts)));
-            mDurationView.setText(Utils.formatDuration(conn.last_seen - conn.first_seen));
-            mFirstSeen.setText(Utils.formatEpochFull(this, conn.first_seen));
-            mLastSeen.setText(Utils.formatEpochFull(this, conn.last_seen));
+            mDurationView.setText(Utils.formatDuration((conn.last_seen - conn.first_seen) / 1000));
+            mFirstSeen.setText(Utils.formatEpochMillis(this, conn.first_seen));
+            mLastSeen.setText(Utils.formatEpochMillis(this, conn.last_seen));
             mStatus.setText(conn.getStatusLabel(this));
 
             if(conn.status >= ConnectionDescriptor.CONN_STATUS_CLOSED)

app/src/main/java/com/emanuelef/remote_capture/adapters/ConnectionsAdapter.java

@@ -120,7 +120,7 @@ public class ConnectionsAdapter extends RecyclerView.Adapter<ConnectionsAdapter.
             String info_txt = (app != null) ? app.getName() : Integer.toString(conn.uid);
             appName.setText(info_txt);
             traffic.setText(Utils.formatBytes(conn.sent_bytes + conn.rcvd_bytes));
-            lastSeen.setText(Utils.formatEpochShort(context, conn.last_seen));
+            lastSeen.setText(Utils.formatEpochShort(context, conn.last_seen / 1000));
             statusInd.setText(conn.getStatusLabel(context));
 
             if(conn.status < ConnectionDescriptor.CONN_STATUS_CLOSED)

app/src/main/jni/common/utils.c

@@ -114,6 +114,12 @@ ssize_t xread(int fd, void *buf, size_t count) {
 
 /* ******************************************************* */
 
+uint64_t timeval2ms(struct timeval *tv) {
+    return (uint64_t)tv->tv_sec * 1000 + tv->tv_usec / 1000;
+}
+
+/* ******************************************************* */
+
 void tupleSwapPeers(zdtun_5tuple_t *tuple) {
     uint16_t tmp = tuple->dst_port;
     tuple->dst_port = tuple->src_port;

app/src/main/jni/common/utils.h

@@ -38,6 +38,7 @@ extern void (*logcallback)(int lvl, const char *msg);
 void log_android(int lvl, const char *fmt, ...);
 ssize_t xwrite(int fd, const void *buf, size_t count);
 ssize_t xread(int fd, void *buf, size_t count);
+uint64_t timeval2ms(struct timeval *tv);
 void tupleSwapPeers(zdtun_5tuple_t *tuple);
 char loglvl2char(int lvl);
 

app/src/main/jni/pcapd/pcapd.c

@@ -601,6 +601,7 @@ static int is_tx_packet(pcapd_runtime_t *rt, const u_char *pkt, u_int16_t len) {
 
 static int run_pcap_dump(int uid_filter, const char *bpf) {
   int rv = -1;
+  struct timespec ts = {0};
   struct pcap_stat stats = {0};
   pcapd_runtime_t rt = {0};
   time_t next_interface_recheck = 0;
@@ -717,7 +718,8 @@ static int run_pcap_dump(int uid_filter, const char *bpf) {
       }
     }
 
-    time_t now = time(NULL);
+    clock_gettime(CLOCK_MONOTONIC_COARSE, &ts);
+    time_t now = ts.tv_sec;
 
     if((rt.pd == NULL) && (now >= next_interface_recheck)) {
       check_capture_interface(&rt);

app/src/main/jni/vpnproxy-jni/capture_proxy.c

@@ -256,7 +256,15 @@ static void on_packet(zdtun_t *tun, const zdtun_pkt_t *pkt, uint8_t from_tun, co
 
     vpnproxy_data_t *proxy = ((vpnproxy_data_t*)zdtun_userdata(tun));
     const zdtun_5tuple_t *tuple = zdtun_conn_get_5tuple(conn_info);
+    struct timespec ts = {0};
 
+    if(!clock_gettime(CLOCK_REALTIME, &ts)) {
+        proxy->last_pkt_ts.tv_sec = ts.tv_sec;
+        proxy->last_pkt_ts.tv_usec = ts.tv_nsec / 1000;
+    } else
+        log_d("clock_gettime failed[%d]: %s", errno, strerror(errno));
+
+    uint64_t pkt_ms = timeval2ms(&proxy->last_pkt_ts);
     data->status = zdtun_conn_get_status(conn_info);
 
     if(shouldIgnoreConn(proxy, tuple)) {
@@ -269,13 +277,13 @@ static void on_packet(zdtun_t *tun, const zdtun_pkt_t *pkt, uint8_t from_tun, co
             data->rcvd_bytes += pkt->len;
         }
 
-        data->last_seen = time(NULL);
+        data->last_seen = pkt_ms;
 
         //log_d("Ignoring connection: UID=%d [filter=%d]", data->uid, proxy->uid_filter);
         return;
     }
 
-    account_packet(proxy, pkt, from_tun, tuple, data);
+    account_packet(proxy, pkt, from_tun, tuple, data, pkt_ms);
 }
 
 /* ******************************************************* */
@@ -434,7 +442,7 @@ int run_proxy(vpnproxy_data_t *proxy) {
             run_housekeeping(proxy);
 
             if(proxy->now_ms >= next_purge_ms) {
-                zdtun_purge_expired(tun, proxy->now_ms / 1000);
+                zdtun_purge_expired(tun);
                 next_purge_ms = proxy->now_ms + PERIODIC_PURGE_TIMEOUT_MS;
             }
     }

app/src/main/jni/vpnproxy-jni/capture_root.c

@@ -277,32 +277,35 @@ static void handle_packet(vpnproxy_data_t *proxy, pcap_conn_t **connections, pca
         }
     }
 
-    account_packet(proxy, &pkt, from_tun, &conn->tuple, conn->data);
+    proxy->last_pkt_ts = hdr->ts;
+
+    uint64_t pkt_ms = (uint64_t)hdr->ts.tv_sec * 1000 + hdr->ts.tv_usec / 1000;
+    account_packet(proxy, &pkt, from_tun, &conn->tuple, conn->data, pkt_ms);
 }
 
 /* ******************************************************* */
 
 static void purge_expired_connections(vpnproxy_data_t *proxy, pcap_conn_t **connections, uint8_t purge_all) {
     pcap_conn_t *conn, *tmp;
-    time_t now = proxy->now_ms / 1000;
+    uint64_t last_pkt_ms = timeval2ms(&proxy->last_pkt_ts);
 
     HASH_ITER(hh, *connections, conn, tmp) {
-        time_t timeout = 0;
+        uint64_t timeout = 0;
 
         // TODO: sync with linux?
         switch(conn->tuple.ipproto) {
             case IPPROTO_TCP:
-                timeout = TCP_TIMEOUT_SEC;
+                timeout = TCP_TIMEOUT_SEC * 1000;
                 break;
             case IPPROTO_UDP:
-                timeout = UDP_TIMEOUT_SEC;
+                timeout = UDP_TIMEOUT_SEC * 1000;
                 break;
             case IPPROTO_ICMP:
-                timeout = ICMP_TIMEOUT_SEC;
+                timeout = ICMP_TIMEOUT_SEC + 1000;
                 break;
         }
 
-        if(purge_all || (conn->data->status >= CONN_STATUS_CLOSED) || (now >= (timeout + conn->data->last_seen))) {
+        if(purge_all || (conn->data->status >= CONN_STATUS_CLOSED) || (last_pkt_ms >= (conn->data->last_seen + timeout))) {
             log_d("IDLE (type=%d)", conn->tuple.ipproto);
 
             // Will free the data in sendConnectionsDump

app/src/main/jni/vpnproxy-jni/pcap_utils.c

@@ -64,14 +64,10 @@ int pcap_rec_size(int pkt_len) {
  * bytes available */
 void pcap_dump_rec(const zdtun_pkt_t *pkt, u_char *buffer, vpnproxy_data_t *proxy, conn_data_t *conn) {
     struct pcaprec_hdr_s *pcap_rec = (pcaprec_hdr_s*) buffer;
-    struct timespec ts = {0};
     int offset = 0;
 
-    if(clock_gettime(CLOCK_REALTIME, &ts))
-        log_d("clock_gettime failed[%d]: %s", errno, strerror(errno));
-
-    pcap_rec->ts_sec = ts.tv_sec;
-    pcap_rec->ts_usec = (ts.tv_nsec / 1000);
+    pcap_rec->ts_sec = proxy->last_pkt_ts.tv_sec;
+    pcap_rec->ts_usec = proxy->last_pkt_ts.tv_usec;
     pcap_rec->incl_len = pcap_rec_size(pkt->len) - (int)sizeof(struct pcaprec_hdr_s);
     pcap_rec->orig_len = pkt->len;
     buffer += sizeof(struct pcaprec_hdr_s);

app/src/main/jni/vpnproxy-jni/vpnproxy.c

@@ -314,7 +314,6 @@ conn_data_t* new_connection(vpnproxy_data_t *proxy, const zdtun_5tuple_t *tuple,
         conn_free_ndpi(data);
     }
 
-    data->first_seen = data->last_seen = time(NULL);
     data->uid = uid;
 
     // Try to resolve host name via the LRU cache
@@ -562,7 +561,7 @@ static void process_ndpi_packet(conn_data_t *data, vpnproxy_data_t *proxy,
 
     u_int16_t old_proto = data->l7proto.master_protocol;
     data->l7proto = ndpi_detection_process_packet(proxy->ndpi, data->ndpi_flow, (const u_char *)pkt->buf,
-                                                  pkt->len, data->last_seen,
+            pkt->len, data->last_seen,
             from_tun ? data->src_id : data->dst_id,
             from_tun ? data->dst_id : data->src_id);
 
@@ -890,10 +889,14 @@ void run_housekeeping(vpnproxy_data_t *proxy) {
 /* ******************************************************* */
 
 void refresh_time(vpnproxy_data_t *proxy) {
-    struct timeval now_tv;
+    struct timespec ts;
 
-    gettimeofday(&now_tv, NULL);
-    proxy->now_ms = (uint64_t)now_tv.tv_sec * 1000 + now_tv.tv_usec / 1000;
+    if(clock_gettime(CLOCK_MONOTONIC_COARSE, &ts)) {
+        log_d("clock_gettime failed[%d]: %s", errno, strerror(errno));
+        return;
+    }
+
+    proxy->now_ms = (uint64_t)ts.tv_sec * 1000 + ts.tv_nsec / 1000000;
 }
 
 /* ******************************************************* */
@@ -928,7 +931,7 @@ void fill_custom_data(struct pcapdroid_trailer *cdata, vpnproxy_data_t *proxy, c
 /* ******************************************************* */
 
 void account_packet(vpnproxy_data_t *proxy, const zdtun_pkt_t *pkt, uint8_t from_tun,
-                    const zdtun_5tuple_t *conn_tuple, conn_data_t *data) {
+                    const zdtun_5tuple_t *conn_tuple, conn_data_t *data, uint64_t pkt_ms) {
 #if 0
     if(from_tun)
         log_d("tun2net: %ld B", size);
@@ -936,7 +939,9 @@ void account_packet(vpnproxy_data_t *proxy, const zdtun_pkt_t *pkt, uint8_t from
         log_d("net2tun: %lu B", size);
 #endif
 
-    data->last_seen = time(NULL);
+    if((data->sent_pkts + data->rcvd_pkts) == 0)
+        data->first_seen = pkt_ms;
+    data->last_seen = pkt_ms;
 
     if(from_tun) {
         data->sent_pkts++;
@@ -998,8 +1003,6 @@ void account_packet(vpnproxy_data_t *proxy, const zdtun_pkt_t *pkt, uint8_t from
 /* ******************************************************* */
 
 static int run_tun(JNIEnv *env, jclass vpn, int tunfd, jint sdk) {
-    last_connections_dump = time(NULL) * 1000;
-    next_connections_dump = last_connections_dump + 500 /* first update after 500 ms */;
     netd_resolve_waiting = 0;
     jclass vpn_class = (*env)->GetObjectClass(env, vpn);
 
@@ -1087,6 +1090,10 @@ static int run_tun(JNIEnv *env, jclass vpn, int tunfd, jint sdk) {
 
     memset(&proxy.stats, 0, sizeof(proxy.stats));
 
+    refresh_time(&proxy);
+    last_connections_dump = proxy.now_ms;
+    next_connections_dump = last_connections_dump + 500 /* first update after 500 ms */;
+
     notifyServiceStatus(&proxy, "started");
 
     // Run the capture

app/src/main/jni/vpnproxy-jni/vpnproxy.h

@@ -111,7 +111,8 @@ typedef struct vpnproxy_data {
     ndpi_ptree_t *known_dns_servers;
     uid_resolver_t *resolver;
     ip_lru_t *ip_to_host;
-    uint64_t now_ms;
+    struct timeval last_pkt_ts; // Packet timestamp, reported into the exported PCAP
+    uint64_t now_ms;            // Monotonic timestamp, see refresh_time
     u_int num_dropped_pkts;
     long num_discarded_fragments;
     u_int32_t num_dropped_connections;
@@ -201,7 +202,8 @@ void conn_free_data(conn_data_t *data);
 void notify_connection(conn_array_t *arr, const zdtun_5tuple_t *tuple, conn_data_t *data);
 void conn_end_ndpi_detection(conn_data_t *data, vpnproxy_data_t *proxy, const zdtun_5tuple_t *tuple);
 void run_housekeeping(vpnproxy_data_t *proxy);
-void account_packet(vpnproxy_data_t *proxy, const zdtun_pkt_t *pkt, uint8_t from_tun, const zdtun_5tuple_t *conn_tuple, conn_data_t *data);
+void account_packet(vpnproxy_data_t *proxy, const zdtun_pkt_t *pkt, uint8_t from_tun,
+                    const zdtun_5tuple_t *conn_tuple, conn_data_t *data, uint64_t pkt_ms);
 int resolve_uid(vpnproxy_data_t *proxy, const zdtun_5tuple_t *conn_info);
 void refresh_time(vpnproxy_data_t *proxy);
 void init_protocols_bitmask(ndpi_protocol_bitmask_struct_t *b);