Merge branch 'master' into develop

schemas/README-EDDN-schemas.md

@@ -98,24 +98,70 @@ value, e.g.
     "$schemaRef": "https://eddn.edcd.io/schemas/shipyard/2/test",
 
 You MUST also utilise these test forms of the schemas when first testing your
-code. There might also be a beta.eddn.edcd.io, or dev.eddn.edcd.io, service
+code.
+
+There might also be a beta.eddn.edcd.io, or dev.eddn.edcd.io, service
 available from time to time as necessary, e.g. for testing new schemas or
-changes to existing ones.
+changes to existing ones.  Ask on the `#eddn` channel of the EDCD Discord 
+(see https://edcd.github.io/ for an invite link).
+
+Alternatively you could attempt
+[running your own test instance of EDDN](../docs/Running-this-software.md).
 
 ### Sending data
-To upload market data to EDDN, you'll need to make a POST request to the URL:
+Messages sent to EDDN **MUST**:
 
-* https://eddn.edcd.io:4430/upload/
+- Use the URL: `https://eddn.edcd.io:4430/upload/`.  Note the use of 
+  TLS-encrypted HTTPS.  A plain HTTP request will elicit a `400 Bad 
+  Request` response.
+- Use the HTTP 1.1 protocol.  HTTP/2 is not supported at this time.
+- Use a **POST** request, with the body containing the EDDN message.  No
+  query parameters in the URL are supported or necessary.
 
-The body of this is a JSON object, so you SHOULD set a `Content-Type` header of
+The body of an EDDN message is a JSON object in UTF-8 encoding.  You SHOULD 
-`applicaton/json`, and NOT any of:
+set a `Content-Type` header of `applicaton/json`, and NOT any of:
 
 * `application/x-www-form-urlencoded`
 * `multipart/form-data`
 * `text/plain`
 
+For historical reasons URL form-encoded data *is* supported, **but this is 
+deprecated and no new software should attempt this method**.
+
+You *MAY* use gzip compression on the body of the message, but it is not 
+required.
+
+You should be prepared to handle all scenarios where sending of a message 
+fails:
+
+1. Connection refused.
+2. Connection timed out.
+3. Other possible responses as documented in
+   [Server responses](#server-responses).
+
+Carefully consider whether you should queue a 'failed' message for later 
+retry.  In particular, you should ensure that one 'bad' message does not 
+block other messages from being successfully sent.
+
+You **MUST** wait some reasonable time (minimum 1 minute) before retrying 
+any failed message.
+
+You **MUST NOT** retry any message that received a HTTP `400` or `426` code.
+An exception can be made if, **and only if**, *you have manually verified that 
+you have fixed the issues with it (i.e. updated the schema/version to a
+currently supported one and adjusted the data to fit that schema/version).*
+
+You **MAY** retry a message that initially received a `413` response (in 
+the hopes that the EDDN service admins decided to increase the maximum 
+allowed request size), but should not do so too quickly or in perpetuity.
+
+In general:
+
+- No data is better than bad data.
+- *Delayed* good data is better than degrading the EDDN service for others.
+
 ### Format of uploaded messages
-Each message is a JSON object in utf-8 encoding containing the following
+Each message is a JSON object in UTF-8 encoding containing the following
 key+value pairs:
 
 1. `$schemaRef` - Which schema (including version) this message is for.
@@ -169,38 +215,130 @@ For example, a shipyard message, version 2, might look like:
 ```
 
 ### Contents of `message`
+Every message MUST comply with the schema its `$schemaRef` value cites.  
+
+Apart from short time windows during deployment of a new version the live 
+EDDN service should always be using
+[the schemas as present in the live branch](https://github.com/EDCD/EDDN/tree/live/schemas).
+So, be sure you're checking the live versions and not, e.g. those in the 
+`master` or other branches.
 
 Each `message` object must have, at bare minimum:
 
-1. `timestamp` - string date and time in ISO8601 format. Whilst that
+1. `timestamp` - string date and time in ISO8601 format. Whilst this
    technically allows for any timezone to be cited you SHOULD provide this in
    UTC, aka 'Zulu Time' as in the example above. You MUST ensure that you are
    doing this properly. Do not claim 'Z' whilst actually using a local time
    that is offset from UTC.
    
+   If you are only utilising Journal-sourced data then simply using the 
+   value from there should be sufficient as the PC game client is meant to 
+   always be correctly citing UTC for this.  Indeed it has been observed, 
+   in the Odyssey 4.0.0.1002 client, that with the Windows clock behind UTC 
+   by 21 seconds both the in-game UI clock *and* the Journal event 
+   timestamps are still properly UTC to the nearest second.
+
    Listeners MAY make decisions on accepting data based on this time stamp,
    i.e. "too old".
-2. One other key/value pair representing the data. In general there will be
+2. At least one other key/value pair representing the data. In general there 
-   much more than this. Again, consult the
+   will be much more than this. Consult the
    [schemas and their documentation](./).
 
-Note that many of the key names chosen in the schemas are based on the CAPI 
+Because the first versions of some schemas were defined when only the CAPI 
-data, not Journal events, because the CAPI came first.  This means renaming 
+data was available, before Journal files existed, many of the key names chosen
-many of the keys from Journal events to match the schema.
+in the schemas are based on the equivalent in CAPI data, not Journal events.
+This means ouy MUST rename many of the keys from Journal events to match the
+schemas.
 
 EDDN is intended to transport generic data not specific to any particular Cmdr
-and to reflect the data that a player would see in-game in station services or
+and to reflect only the data that every player would see in-game in station 
-the local map. To that end, uploading applications MUST ensure that messages do
+services or the local map. To that end, uploading applications MUST ensure
-not contain any Cmdr-specific data (other than "uploaderID" and the "horizons"
+that messages do not contain any Cmdr-specific data (other than "uploaderID",
-flag).
+the "horizons" flag, and the "odyssey" flag).
 
 The individual schemas will instruct you on various elisions (removals) to 
 be made to comply with this.
 
 Some of these requirements are also enforced by the schemas, and some things
-the schemas enforce might not be explicitly called out here, so **do**
+the schemas enforce might not be explicitly called out here.  So, **do**
-check what you're sending against the schema when implementing sending new
+check what you're sending against the relevant schema(s) when making any 
-events.
+changes to your code.
+
+It is also advisable to Watch this repository on GitHub so as to be aware 
+of any changes to schemas.
+
+### Server responses
+There are three possible sources of HTTP responses when sending an upload 
+to EDDN.
+
+1. The reverse proxy that initially accepts the request.
+2. The python `bottle` module that the Gateway uses to process the 
+   forwarded requests.  This might object to a message before the actual 
+   EDDN code gets to process it at all.
+3. The actual EDDN Gateway code.
+
+Once a message has cleared the EDDN Gateway then there is no mechanism for any 
+further issue (such as a message being detected as a duplicate in the 
+Monitor downstream of the Gateway) to be reported back to the sender.
+
+To state the obvious, if there are no issues with a request then an HTTP 
+200 response will be received by the sender.  The body of the response 
+should be the string `OK`.
+
+#### Reverse Proxy responses
+In addition to generic "you typoed the URL" and other such "you just didn't 
+make a valid request" responses you might experience the following:
+
+1. `408` - `Request Timed Out` - the sender took too long to make/complete 
+   its request and the reverse proxy rejected it as a result.
+2. `503` - `Service Unavailable` - the EDDN Gateway process is either not 
+   running, or not responding.
+
+#### bottle responses
+1. `413` - `Payload Too Large` - `bottle` enforces a maximum request size 
+   and the request exceeds that.  As of 2022-01-07 the limit is 1MiB, and 
+   pertains to the plain-text size, not after gzip compression if used.
+   To verify the current limit check for the line that looks like:
+
+      ```
+      bottle.BaseRequest.MEMFILE_MAX = 1024 * 1024 # 1MiB, default is/was 100KiB
+      ```
+   
+   in
+   [src/eddn/Gateway.py](https://github.com/EDCD/EDDN/blob/master/src/eddn/Gateway.py),
+   as added in
+   [commit  0e80c76cb564771465f61825e694227dcc3be312](https://github.com/EDCD/EDDN/commit/0e80c76cb564771465f61825e694227dcc3be312).
+
+#### EDDN Gateway responses
+1. `400` - `Bad Request` - this can be for a variety of reasons, and should 
+   come with a response body with prefix `OK: ` or `FAIL: `:
+    1. `FAIL: <python simplejson exception message>` - the request couldn't be 
+       parsed as valid JSON.  e.g.
+
+    ```
+    FAIL: Expecting property name enclosed in double quotes: line 1 column 2 (char 1)
+    ```
+    2. `FAIL: [<ValidationError: "<schema validation failure>"]` - the JSON 
+       message failed to pass schema validation.  e.g.
+
+    ```
+    FAIL: [<ValidationError: "'StarPos' is a required property">]
+    ```
+
+    3. Other python exception message, e.g. if a message appeared to be 
+       gzip compressed, but a failure was experienced when attempting to 
+       decompress it.  **NB: As of 2022-07-01 such messages won't have the 
+       `FAIL: ` prefix.**  See
+       [#161 - Gateway: Improve reporting of 'misc' errors ](https://github.com/EDCD/EDDN/issues/161)
+       for any progress/resolution on this.
+
+2. `426` - `Upgrade Required` - You sent a message with an outdated 
+   `$schemaRef` value.  This could be either an old, deprecated version of 
+   a schema, or an entirely deprecated schema.  e.g.
+
+   ```
+   FAIL: The schema you have used is no longer supported. Please check for an updated version of your application.
+   ```
 
 ## Receiving messages
 

schemas/codexentry-README.md

@@ -64,7 +64,7 @@ release, Update 7, plus one patch).
    away.
 5. If Status.json does **not** have `BodyName` then clear `status_body_name`.
 6. For a `CodexEntry` event:
-    1. Check that `status_body_name` is set. If it is not, exit.
+    1. Only if `status_body_name` is set:
         1. Set the EDDN `codexentry` schema message `BodyName` to this value.
         2. Check if it matches the `journal_body_name` value, and 
            ONLY if they match, set `BodyID` in the EDDN `codexentry`
@@ -121,4 +121,4 @@ So you might receive any of:
 3. Both `BodyName` and `BodyID` keys present, with values.  This SHOULD 
    indicate a codex entry object which is on a body surface.
 
-Adjust your local processing accordingly.
+Adjust your local processing accordingly.

src/eddn/Gateway.py

@@ -21,10 +21,23 @@ from eddn.core.Validator import Validator, ValidationSeverity
 
 from gevent import monkey
 monkey.patch_all()
+import bottle
 from bottle import Bottle, run, request, response, get, post
+bottle.BaseRequest.MEMFILE_MAX = 1024 * 1024 # 1MiB, default is/was 100KiB
 app = Bottle()
 
 logger = logging.getLogger(__name__)
+logger.setLevel(logging.INFO)
+__logger_channel = logging.StreamHandler()
+__logger_formatter = logging.Formatter(
+    '%(asctime)s - %(levelname)s - %(module)s:%(lineno)d: %(message)s'
+)
+__logger_formatter.default_time_format = '%Y-%m-%d %H:%M:%S'
+__logger_formatter.default_msec_format = '%s.%03d'
+__logger_channel.setFormatter(__logger_formatter)
+logger.addHandler(__logger_channel)
+logger.info('Made logger')
+
 
 # This socket is used to push market data out to the Announcers over ZeroMQ.
 context = zmq.Context()
@@ -38,6 +51,37 @@ statsCollector = StatsCollector()
 statsCollector.start()
 
 
+def extract_message_details(parsed_message):
+    uploader_id = '<<UNKNOWN>>'
+    software_name = '<<UNKNOWN>>'
+    software_version = '<<UNKNOWN>>'
+    schema_ref = '<<UNKNOWN>>'
+    journal_event = '<<UNKNOWN>>'
+
+    if 'header' in parsed_message:
+        if 'uploaderID' in parsed_message['header']:
+            uploader_id = parsed_message['header']['uploaderID']
+
+        if 'softwareName' in parsed_message['header']:
+            software_name = parsed_message['header']['softwareName']
+
+        if 'softwareVersion' in parsed_message['header']:
+            software_version = parsed_message['header']['softwareVersion']
+
+    if '$schemaRef' in parsed_message:
+        schema_ref = parsed_message['$schemaRef']
+
+
+        if '/journal/' in schema_ref:
+            if 'message' in parsed_message:
+                if 'event' in parsed_message['message']:
+                    journal_event = parsed_message['message']['event']
+
+        else:
+            journal_event = '-'
+
+    return uploader_id, software_name, software_version, schema_ref, journal_event
+
 def configure():
     # Get the list of transports to bind from settings. This allows us to PUB
     # messages to multiple announcers over a variety of socket types
@@ -131,9 +175,24 @@ def parse_and_error_handle(data):
     ) as exc:
         # Something bad happened. We know this will return at least a
         # semi-useful error message, so do so.
+        try:
+            logger.error('Error - JSON parse failed (%d, "%s", "%s", "%s", "%s", "%s") from %s:\n%s\n' % (
+                    request.content_length,
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    get_remote_address(),
+                    data[:512]
+            ))
+
+        except Exception as e:
+            print('Logging of "JSON parse failed" failed: %s' % (e.message))
+            pass
+
         response.status = 400
-        logger.error("Error to %s: %s" % (get_remote_address(), exc.message))
+        return 'FAIL: ' + str(exc)
-        return str(exc)
 
     # Here we check if an outdated schema has been passed
     if parsed_message["$schemaRef"] in Settings.GATEWAY_OUTDATED_SCHEMAS:
@@ -149,11 +208,35 @@ def parse_and_error_handle(data):
 
         # Sends the parsed message to the Relay/Monitor as compressed JSON.
         gevent.spawn(push_message, parsed_message, parsed_message['$schemaRef'])
-        logger.info("Accepted %s upload from %s" % (
+
-            parsed_message, get_remote_address()
+        try:
-        ))
+            uploader_id, software_name, software_version, schema_ref, journal_event = extract_message_details(parsed_message)
+            logger.info('Accepted (%d, "%s", "%s", "%s", "%s", "%s") from %s' % (
+                request.content_length,
+                uploader_id, software_name, software_version, schema_ref, journal_event,
+                get_remote_address()
+            ))
+
+        except Exception as e:
+            print('Logging of Accepted request failed: %s' % (e.message))
+            pass
+
         return 'OK'
+
     else:
+        try:
+            uploader_id, software_name, software_version, schema_ref, journal_event = extract_message_details(parsed_message)
+            logger.error('Failed Validation "%s" (%d, "%s", "%s", "%s", "%s", "%s") from %s' % (
+                    str(validationResults.messages),
+                    request.content_length,
+                    uploader_id, software_name, software_version, schema_ref, journal_event,
+                    get_remote_address()
+            ))
+
+        except Exception as e:
+            print('Logging of Failed Validation failed: %s' % (e.message))
+            pass
+
         response.status = 400
         statsCollector.tally("invalid")
         return "FAIL: " + str(validationResults.messages)
@@ -164,17 +247,34 @@ def upload():
     try:
         # Body may or may not be compressed.
         message_body = get_decompressed_message()
+
     except zlib.error as exc:
         # Some languages and libs do a crap job zlib compressing stuff. Provide
         # at least some kind of feedback for them to try to get pointed in
         # the correct direction.
         response.status = 400
-        logger.error("gzip error with %s: %s" % (get_remote_address(), exc.message))
+        try:
+            logger.error('gzip error (%d, "%s", "%s", "%s", "%s", "%s") from %s' % (
+                    request.content_length,
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    '<<UNKNOWN>>',
+                    get_remote_address()
+            ))
+
+        except Exception as e:
+            print('Logging of "gzip error" failed: %s' % (e.message))
+            pass
+
         return exc.message
+
     except MalformedUploadError as exc:
         # They probably sent an encoded POST, but got the key/val wrong.
         response.status = 400
-        logger.error("Error to %s: %s" % (get_remote_address(), exc.message))
+        logger.error("MalformedUploadError from %s: %s" % (get_remote_address(), exc.message))
+
         return exc.message
 
     statsCollector.tally("inbound")