Record and report server entry source and receipt time

AndroidLibrary/psi/psi.go

@@ -75,7 +75,10 @@ func Start(
 		return fmt.Errorf("error initializing datastore: %s", err)
 	}
 
-	serverEntries, err := psiphon.DecodeAndValidateServerEntryList(embeddedServerEntryList)
+	serverEntries, err := psiphon.DecodeAndValidateServerEntryList(
+		embeddedServerEntryList,
+		psiphon.GetCurrentTimestamp(),
+		psiphon.SERVER_ENTRY_SOURCE_EMBEDDED)
 	if err != nil {
 		return fmt.Errorf("error decoding embedded server entry list: %s", err)
 	}

ConsoleClient/psiphonClient.go

@@ -135,7 +135,10 @@ func main() {
 				return
 			}
 			// TODO: stream embedded server list data? also, the cast makes an unnecessary copy of a large buffer?
-			serverEntries, err := psiphon.DecodeAndValidateServerEntryList(string(serverEntryList))
+			serverEntries, err := psiphon.DecodeAndValidateServerEntryList(
+				string(serverEntryList),
+				psiphon.GetCurrentTimestamp(),
+				psiphon.SERVER_ENTRY_SOURCE_EMBEDDED)
 			if err != nil {
 				psiphon.NoticeError("error decoding embedded server entry list file: %s", err)
 				return

psiphon/dataStore.go

@@ -396,7 +396,8 @@ func NewServerEntryIterator(config *Config) (iterator *ServerEntryIterator, err
 
 // newTargetServerEntryIterator is a helper for initializing the TargetServerEntry case
 func newTargetServerEntryIterator(config *Config) (iterator *ServerEntryIterator, err error) {
-	serverEntry, err := DecodeServerEntry(config.TargetServerEntry)
+	serverEntry, err := DecodeServerEntry(
+		config.TargetServerEntry, GetCurrentTimestamp(), SERVER_ENTRY_SOURCE_TARGET)
 	if err != nil {
 		return nil, err
 	}

psiphon/remoteServerList.go

@@ -86,7 +86,10 @@ func FetchRemoteServerList(config *Config, dialConfig *DialConfig) (err error) {
 		return ContextError(err)
 	}
 
-	serverEntries, err := DecodeAndValidateServerEntryList(remoteServerList)
+	serverEntries, err := DecodeAndValidateServerEntryList(
+		remoteServerList,
+		GetCurrentTimestamp(),
+		SERVER_ENTRY_SOURCE_REMOTE)
 	if err != nil {
 		return ContextError(err)
 	}

psiphon/serverApi.go

@@ -161,11 +161,18 @@ func (serverContext *ServerContext) doHandshakeRequest() error {
 	var decodedServerEntries []*ServerEntry
 
 	// Store discovered server entries
+	// We use the server's time, as it's available here, for the server entry
+	// timestamp since this is more reliable than the client time.
 	for _, encodedServerEntry := range handshakeConfig.EncodedServerList {
-		serverEntry, err := DecodeServerEntry(encodedServerEntry)
+
+		serverEntry, err := DecodeServerEntry(
+			encodedServerEntry,
+			TruncateTimestampToHour(handshakeConfig.ServerTimestamp),
+			SERVER_ENTRY_SOURCE_DISCOVERY)
 		if err != nil {
 			return ContextError(err)
 		}
+
 		err = ValidateServerEntry(serverEntry)
 		if err != nil {
 			// Skip this entry and continue with the next one
@@ -622,6 +629,16 @@ func makeBaseRequestUrl(tunnel *Tunnel, port, sessionId string) string {
 			requestUrl.WriteString("0")
 		}
 	}
+	requestUrl.WriteString("&server_entry_source=")
+	requestUrl.WriteString(tunnel.serverEntry.LocalSource)
+	requestUrl.WriteString("&server_entry_timestamp=")
+
+	// As with last_connected, this timestamp stat, which may be
+	// a precise handshake request server timestamp, is truncated
+	// to hour granularity to avoid introducing a reconstructable
+	// cross-session user trace into server logs.
+	requestUrl.WriteString(
+		TruncateTimestampToHour(tunnel.serverEntry.LocalTimestamp))
 
 	return requestUrl.String()
 }

psiphon/serverEntry.go

@@ -46,8 +46,8 @@ var SupportedTunnelProtocols = []string{
 }
 
 // ServerEntry represents a Psiphon server. It contains information
-// about how to estalish a tunnel connection to the server through
-// several protocols. ServerEntry are JSON records downloaded from
+// about how to establish a tunnel connection to the server through
+// several protocols. Server entries are JSON records downloaded from
 // various sources.
 type ServerEntry struct {
 	IpAddress                     string   `json:"ipAddress"`
@@ -69,8 +69,23 @@ type ServerEntry struct {
 	MeekFrontingDomain            string   `json:"meekFrontingDomain"`
 	MeekFrontingAddresses         []string `json:"meekFrontingAddresses"`
 	MeekFrontingAddressesRegex    string   `json:"meekFrontingAddressesRegex"`
+
+	// These local fields are not expected to be present in downloaded server
+	// entries. They are added by the client to record and report stats about
+	// how and when server entries are obtained.
+	LocalSource    string `json:"localSource"`
+	LocalTimestamp string `json:"localTimestamp"`
 }
 
+type ServerEntrySource string
+
+const (
+	SERVER_ENTRY_SOURCE_EMBEDDED  ServerEntrySource = "EMBEDDED"
+	SERVER_ENTRY_SOURCE_REMOTE                      = "REMOTE"
+	SERVER_ENTRY_SOURCE_DISCOVERY                   = "DISCOVERY"
+	SERVER_ENTRY_SOURCE_TARGET                      = "TARGET"
+)
+
 // SupportsProtocol returns true if and only if the ServerEntry has
 // the necessary capability to support the specified tunnel protocol.
 func (serverEntry *ServerEntry) SupportsProtocol(protocol string) bool {
@@ -127,22 +142,39 @@ func (serverEntry *ServerEntry) GetDirectWebRequestPorts() []string {
 
 // DecodeServerEntry extracts server entries from the encoding
 // used by remote server lists and Psiphon server handshake requests.
-func DecodeServerEntry(encodedServerEntry string) (serverEntry *ServerEntry, err error) {
+//
+// The resulting ServerEntry.LocalSource is populated with serverEntrySource,
+// which should be one of SERVER_ENTRY_SOURCE_EMBEDDED, SERVER_ENTRY_SOURCE_REMOTE,
+// SERVER_ENTRY_SOURCE_DISCOVERY, SERVER_ENTRY_SOURCE_TARGET.
+// ServerEntry.LocalTimestamp is populated with the provided timestamp, which
+// should be a RFC 3339 formatted string. These local fields are stored with the
+// server entry and reported to the server as stats (a coarse granularity timestamp
+// is reported).
+func DecodeServerEntry(
+	encodedServerEntry, timestamp string,
+	serverEntrySource ServerEntrySource) (serverEntry *ServerEntry, err error) {
+
 	hexDecodedServerEntry, err := hex.DecodeString(encodedServerEntry)
 	if err != nil {
 		return nil, ContextError(err)
 	}
+
 	// Skip past legacy format (4 space delimited fields) and just parse the JSON config
 	fields := bytes.SplitN(hexDecodedServerEntry, []byte(" "), 5)
 	if len(fields) != 5 {
 		return nil, ContextError(errors.New("invalid encoded server entry"))
 	}
+
 	serverEntry = new(ServerEntry)
 	err = json.Unmarshal(fields[4], &serverEntry)
 	if err != nil {
 		return nil, ContextError(err)
 	}
 
+	// NOTE: if the source JSON happens to have values in these fields, they get clobbered.
+	serverEntry.LocalSource = string(serverEntrySource)
+	serverEntry.LocalTimestamp = timestamp
+
 	return serverEntry, nil
 }
 
@@ -166,7 +198,11 @@ func ValidateServerEntry(serverEntry *ServerEntry) error {
 // DecodeAndValidateServerEntryList extracts server entries from the list encoding
 // used by remote server lists and Psiphon server handshake requests.
 // Each server entry is validated and invalid entries are skipped.
-func DecodeAndValidateServerEntryList(encodedServerEntryList string) (serverEntries []*ServerEntry, err error) {
+// See DecodeServerEntry for note on serverEntrySource/timestamp.
+func DecodeAndValidateServerEntryList(
+	encodedServerEntryList, timestamp string,
+	serverEntrySource ServerEntrySource) (serverEntries []*ServerEntry, err error) {
+
 	serverEntries = make([]*ServerEntry, 0)
 	for _, encodedServerEntry := range strings.Split(encodedServerEntryList, "\n") {
 		if len(encodedServerEntry) == 0 {
@@ -174,7 +210,7 @@ func DecodeAndValidateServerEntryList(encodedServerEntryList string) (serverEntr
 		}
 
 		// TODO: skip this entry and continue if can't decode?
-		serverEntry, err := DecodeServerEntry(encodedServerEntry)
+		serverEntry, err := DecodeServerEntry(encodedServerEntry, timestamp, serverEntrySource)
 		if err != nil {
 			return nil, ContextError(err)
 		}

psiphon/serverEntry_test.go

@@ -40,7 +40,8 @@ func TestDecodeAndValidateServerEntryList(t *testing.T) {
 		hex.EncodeToString([]byte(_INVALID_WINDOWS_REGISTRY_LEGACY_SERVER_ENTRY)) + "\n" +
 		hex.EncodeToString([]byte(_INVALID_MALFORMED_IP_ADDRESS_SERVER_ENTRY))
 
-	serverEntries, err := DecodeAndValidateServerEntryList(testEncodedServerEntryList)
+	serverEntries, err := DecodeAndValidateServerEntryList(
+		testEncodedServerEntryList, GetCurrentTimestamp(), SERVER_ENTRY_SOURCE_EMBEDDED)
 	if err != nil {
 		t.Error(err.Error())
 		t.FailNow()
@@ -62,7 +63,8 @@ func TestInvalidServerEntries(t *testing.T) {
 
 	for _, testCase := range testCases {
 		encodedServerEntry := hex.EncodeToString([]byte(testCase))
-		serverEntry, err := DecodeServerEntry(encodedServerEntry)
+		serverEntry, err := DecodeServerEntry(
+			encodedServerEntry, GetCurrentTimestamp(), SERVER_ENTRY_SOURCE_EMBEDDED)
 		if err != nil {
 			t.Error(err.Error())
 		}

psiphon/utils.go

@@ -212,3 +212,21 @@ func (writer *SyncFileWriter) Write(p []byte) (n int, err error) {
 	}
 	return
 }
+
+// GetCurrentTimestamp returns the current time in UTC as
+// an RFC 3339 formatted string.
+func GetCurrentTimestamp() string {
+	return time.Now().UTC().Format(time.RFC3339)
+}
+
+// TruncateTimestampToHour truncates an RFC 3339 formatted string
+// to hour granularity. If the input is not a valid format, the
+// result is "".
+func TruncateTimestampToHour(timestamp string) string {
+	t, err := time.Parse(time.RFC3339, timestamp)
+	if err != nil {
+		NoticeAlert("failed to truncate timestamp: %s", err)
+		return ""
+	}
+	return t.Truncate(1 * time.Hour).Format(time.RFC3339)
+}