Extend spec coverage file with concrete requests and responses. (#170)

This change adds an example of a concrete request for which the
data in the spec coverage file is reported.

The goal of this change is that information in the spec coverage file
can be used to troubleshoot failing requests using only:

- the spec coverage file
- backend logs for the service

The diff speccov script has been modified to avoid diffing the
concrete data that is now in the coverage file.

Author: marina-p

docs/user-guide/Testing.md

@@ -71,6 +71,24 @@ Each request is represented by a hash of its definition.
         "status_code": "400",
         "status_text": "BAD REQUEST",
         "error_message": "{\n    \"errors\": {\n        \"id\": \"'5882' is not of type 'integer'\"\n    },\n    \"message\": \"Input payload validation failed\"\n}\n",
+        "sample_request": {
+            "request_sent_timestamp": null,
+            "response_received_timestamp": "2021-03-31 18:20:14",
+            "request_uri": "/api/blog/posts/5882",
+            "request_headers": [
+                "Accept: application/json",
+                "Host: localhost:8888",
+                "Content-Type: application/json"
+            ],
+            "request_body": "{\n    \"id\":\"5882\",\n    \"checksum\":\"fuzzstring\",\n    \"body\":\"fuzzstring\"}\r\n",
+            "response_headers": [
+                "Content-Type: application/json",
+                "Content-Length: 124",
+                "Server: Werkzeug/0.16.0 Python/3.7.8",
+                "Date: Wed, 31 Mar 2021 18:20:14 GMT"
+            ],
+            "response_body": "{\n    \"errors\": {\n        \"id\": \"'5882' is not of type 'integer'\"\n    },\n    \"message\": \"Input payload validation failed\"\n}\n"
+        },
         "request_order": 4
     },
 ```
@@ -92,6 +110,8 @@ the appropriate __"invalid_due_to_..."__ value will be set to 1.
   but there was a failure while parsing the response data.
   * "500" will be set if a 5xx bug was detected.
 * The __"status_code"__ and __"status_text"__ values are the response values received from the server.
+* The __"sample_request"__ contains the concrete values of the sent request and received response for which
+the coverage data is being reported.
 * The __"error_message"__ value will be set to the response body if the request was not "valid".
 * The __"request_order"__ value is the 0 indexed order that the request was sent.
   * Requests sent during "preprocessing" or "postprocessing" will explicitely say so.

restler/engine/core/driver.py

@@ -365,7 +365,8 @@ def render_request(request, seq):
 
         Side effects: request.stats.status_code updated
                       request.stats.status_text updated
-
+                      request.stats updated with concrete response and request text
+                      (valid request or last combination)
         @return: Tuple containing rendered sequence object, response body, and
                  failure information enum.
         @rtype : Tuple(RenderedSequence, str, FailureInformation)
@@ -387,8 +388,15 @@ def render_request(request, seq):
             # will be returned from seq.render if all request combinations are
             # exhausted prior to getting a valid status code.
             if renderings.final_request_response:
+
                 request.stats.status_code = renderings.final_request_response.status_code
                 request.stats.status_text = renderings.final_request_response.status_text
+                # Get the last rendered request.  The corresponding response should be
+                # the last received response.
+                request.stats.sample_request.set_request_stats(
+                    renderings.sequence.sent_request_data_list[-1].rendered_data)
+                request.stats.sample_request.set_response_stats(renderings.final_request_response,
+                                                                renderings.final_response_datetime)
                 response_body = renderings.final_request_response.body
 
             apply_checkers(checkers, renderings, global_lock)

restler/engine/core/fuzzer.py

@@ -5,6 +5,7 @@
 
 import engine.core.driver as driver
 import utils.logger as logger
+import traceback
 
 from engine.core.fuzzing_monitor import Monitor
 from engine.core.requests import GrammarRequestCollection
@@ -52,7 +53,7 @@ def run(self):
         except InvalidDictionaryException:
             pass
         except Exception as err:
-            self._exception = str(err)
+            self._exception = traceback.format_exc()
 
     def join(self, *args):
         """ Overrides thread join function

restler/engine/core/postprocessing.py

@@ -54,6 +54,12 @@ def delete_create_once_resources(destructors, fuzzing_requests):
                 destructor.stats.valid = 1
                 destructor.stats.status_code = renderings.final_request_response.status_code
                 destructor.stats.status_text = renderings.final_request_response.status_text
+
+                destructor.stats.sample_request.set_request_stats(
+                    renderings.sequence.sent_request_data_list[-1].rendered_data)
+                destructor.stats.sample_request.set_response_stats(renderings.final_request_response,
+                                                                   renderings.final_response_datetime)
+
         except Exception as error:
             msg = f"Failed to delete create_once resource: {error!s}"
             logger.raw_network_logging(msg)
@@ -65,6 +71,10 @@ def delete_create_once_resources(destructors, fuzzing_requests):
                     destructor.stats.status_code = renderings.final_request_response.status_code
                     destructor.stats.status_text = renderings.final_request_response.status_text
                     destructor.stats.error_msg = renderings.final_request_response.body
+                    destructor.stats.sample_request.set_request_stats(
+                        renderings.sequence.sent_request_data_list[-1].rendered_data)
+                    destructor.stats.sample_request.set_response_stats(renderings.final_request_response, renderings.final_response_datetime)
+
             pass
 
     Monitor().current_fuzzing_generation += 1

restler/engine/core/preprocessing.py

@@ -211,6 +211,11 @@ def exclude_requests(pre_reqs, post_reqs):
                         resource_gen_req.stats.valid = 1
                         resource_gen_req.stats.status_code = renderings.final_request_response.status_code
                         resource_gen_req.stats.status_text = renderings.final_request_response.status_text
+                        resource_gen_req.stats.sample_request.set_request_stats(
+                            renderings.sequence.sent_request_data_list[-1].rendered_data)
+                        resource_gen_req.stats.sample_request.set_response_stats(renderings.final_request_response,
+                                                                                 renderings.final_response_datetime)
+
                 if req.is_destructor():
                     # Add destructors to the destructor list that will be returned
                     destructors.add(req)

restler/engine/core/requests.py

@@ -22,6 +22,7 @@
 import engine.dependencies as dependencies
 import engine.mime.multipart_formdata as multipart_formdata
 from enum import Enum
+from engine.transport_layer import messaging
 
 class EmptyRequestException(Exception):
     pass
@@ -35,17 +36,72 @@ class FailureInformation(Enum):
     PARSER = 3
     BUG = 4
 
+class RenderedRequestStats(object):
+    """ Class used for encapsulating data about a specific rendered request and its response.
+        This data is included in the spec coverage report.
+        However, this data includes run-specific information
+        and should not be used for diffing spec coverage. """
+    def __init__(self):
+        self.request_sent_timestamp = None
+        self.response_received_timestamp = None
+
+        self.request_uri = None
+        self.request_headers = None
+        self.request_body = None
+
+        self.response_headers = None
+        self.response_body = None
+
+    def set_request_stats(self, request_text):
+        """ Helper to set the request statistics from the text.
+            Parses the request text and initializes headers, uri, and body
+            separately.
+
+        @return: None
+        @rtype : None
+
+        """
+        try:
+            split_body = request_text.split(messaging.DELIM)
+            split_headers = split_body[0].split("\r\n")
+            self.request_uri = split_headers[0].split(" ")[1]
+            self.request_headers = split_headers[1:]
+
+            if len(split_body) > 0 and split_body[1]:
+                self.request_body = split_body[1]
+        except:
+            logger.write_to_main(
+                            f"Error setting request stats for text: {request_text}",
+                            print_to_console=True
+                        )
+            pass
+
+    def set_response_stats(self, final_request_response, final_response_datetime):
+        """ Helper to set the response headers and body.
+
+        @return: None
+        @rtype : None
+
+        """
+        self.response_headers = final_request_response.headers
+        self.response_body = final_request_response.body
+        self.response_received_timestamp = final_response_datetime
+
+
 class SmokeTestStats(object):
     """ Class used for logging stats during directed-smoke-test """
     def __init__(self):
         self.request_order = -1
         self.matching_prefix = {} # {"id": <prefix_hex>, "valid": <0/1>}
         self.valid = 0
         self.failure = None
+
         self.error_msg = None
         self.status_code = None
         self.status_text = None
 
+        self.sample_request = RenderedRequestStats()
+
 class Request(object):
     """ Request Class. """
     def __init__(self, definition=[], requestId=None):

restler/engine/core/sequences.py

@@ -8,6 +8,7 @@
 import copy
 import time
 import json
+import datetime
 
 import engine.core.async_request_utilities as async_request_utilities
 import engine.core.request_utilities as request_utilities
@@ -42,7 +43,8 @@ def __init__(self, rendered_data, parser, response="", producer_timing_delay=0,
 
 class RenderedSequence(object):
     """ RenderedSequence class """
-    def __init__(self, sequence=None, valid=False, failure_info=None, final_request_response=None):
+    def __init__(self, sequence=None, valid=False, failure_info=None, final_request_response=None,
+                 response_datetime=None):
         """ Initializes RenderedSequence object
 
         @param sequence: The sequence that was rendered
@@ -59,6 +61,7 @@ def __init__(self, sequence=None, valid=False, failure_info=None, final_request_
         self.valid = valid
         self.failure_info = failure_info
         self.final_request_response = final_request_response
+        self.final_response_datetime = response_datetime
 
 class Sequence(object):
     """ Implements basic sequence logic.  """
@@ -413,7 +416,9 @@ def render(self, candidate_values_pool, lock, preprocessing=False, postprocessin
                 and not resource_error\
                 and response.has_valid_code()
             # register latest client/server interaction and add to the status codes list
-            timestamp_micro = int(time.time()*10**6)
+            response_datetime = datetime.datetime.now(datetime.timezone.utc)
+            timestamp_micro = int(response_datetime.timestamp()*10**6)
+
             self.status_codes.append(status_codes_monitor.RequestExecutionStatus(timestamp_micro,
                                                                      request.hex_definition,
                                                                      status_code,
@@ -449,9 +454,11 @@ def render(self, candidate_values_pool, lock, preprocessing=False, postprocessin
             if lock is not None:
                 lock.release()
 
+            datetime_format = "%Y-%m-%d %H:%M:%S"
             # return a rendered clone if response indicates a valid status code
             if rendering_is_valid or Settings().ignore_feedback:
-                return RenderedSequence(duplicate, valid=True, final_request_response=response)
+                return RenderedSequence(duplicate, valid=True, final_request_response=response,
+                                        response_datetime=response_datetime.strftime(datetime_format))
             else:
                 information = None
                 if response.has_valid_code():
@@ -461,7 +468,9 @@ def render(self, candidate_values_pool, lock, preprocessing=False, postprocessin
                         information = FailureInformation.RESOURCE_CREATION
                 elif response.has_bug_code():
                     information = FailureInformation.BUG
-                return RenderedSequence(duplicate, valid=False, failure_info=information, final_request_response=response)
+                return RenderedSequence(duplicate, valid=False, failure_info=information,
+                                        final_request_response=response,
+                                        response_datetime=response_datetime.strftime(datetime_format))
 
         return RenderedSequence(None)
 

restler/engine/transport_layer/response.py

@@ -66,6 +66,21 @@ def body(self):
         except:
             return None
 
+    @property
+    def headers(self):
+        """ The headers of the response
+
+        @return: The headers
+        @rtype : List[Str]
+
+        """
+        try:
+            response_without_body = self._str.split(DELIM)[0]
+            # assumed format: HTTP/1.1 STATUS_CODE STATUS TEXT\r\nresponse...
+            return response_without_body.split(" ", 2)[2].split('\r\n')[1:]
+        except:
+            return None
+
     @property
     def json_body(self):
         """ The json portion of the body if exists.

restler/utils/logger.py

@@ -890,6 +890,7 @@ def print_spec_coverage(fuzzing_requests):
             req_spec['invalid_due_to_500'] = 1
         req_spec['status_code'] = req.stats.status_code
         req_spec['status_text'] = req.stats.status_text
+        req_spec['sample_request'] = vars(req.stats.sample_request)
         req_spec['error_message'] = req.stats.error_msg
         req_spec['request_order'] = req.stats.request_order
 

utilities/speccovparsing/diff_speccov.py

@@ -28,6 +28,9 @@ def diff_reqs(left_req, right_req):
     # NOTE: Any differences in keys here will either cause a failure or be
     # ignored. The files are expected to have matching formats.
     for key in left_req.keys():
+        # Skip the sample request, which contains concrete values in paths, timestamps, etc.
+        if key == "sample_request":
+            continue
         try:
             if (type(left_req[key]) != type(right_req[key]))\
             or left_req[key] != right_req[key]: