Repository: oasis-open/cti-stix-validator

Issue:
The validator logger has introduced problems for the elevator logger
Once the validator 1.0.1 was used with the elevator, each elevator message was output twice.

This temporary fix (https://github.com/oasis-open/cti-stix-elevator/commit/b7ce45baf17c0652afaf536415a3781021000f49) in the elevator solved the problem, but we should look into how loggers work together when stix utilities call each other. 
print_results: 'ObjectValidationResults' object is not iterable
```python3
from stix2validator import validate_string, print_results    
results = validate_string(sample.stix2)      
print_results(results)     
```

Produces:

  File "lib/python3.6/site-packages/stix2validator/output.py", line 152, in print_results
    for file_result in sorted(results, key=operator.attrgetter("filepath")):
TypeError: 'ObjectValidationResults' object is not iterable

Using:

stix2-validator==1.0.1
Python 3.6.3


Discussion:

Patch:
diff --git a/stix2validator/__init__.py b/stix2validator/__init__.py
index 83efa8d..7cc2db5 100644
--- a/stix2validator/__init__.py
+++ b/stix2validator/__init__.py
@@ -1,7 +1,6 @@
 # Expose certain functions and classes to the stix2validator namespace
 # flake8: noqa
 
-import logging
 import sys
 
 from .errors import ValidationError
@@ -11,5 +10,3 @@ from .validator import (run_validation, validate, validate_file,
                         validate_instance, validate_parsed_json,
                         validate_string)
 from .version import __version__
-
-logging.basicConfig(stream=sys.stdout, level=logging.INFO, format='%(message)s')
diff --git a/stix2validator/output.py b/stix2validator/output.py
index b2f3030..f011807 100644
--- a/stix2validator/output.py
+++ b/stix2validator/output.py
@@ -1,5 +1,4 @@
 import logging
-import operator
 import sys
 
 from colorama import Fore, Style, init
@@ -36,7 +35,7 @@ def set_silent(silence_output=False):
 
 
 def error(msg, status=codes.EXIT_FAILURE):
-    """Prints a message to the stderr prepended by '[X]' and calls
+    """Print a message to the stderr prepended by '[X]' and calls
     ```sys.exit(status)``.
 
     Args:
@@ -49,7 +48,7 @@ def error(msg, status=codes.EXIT_FAILURE):
 
 
 def info(msg):
-    """Prints a message to stdout, prepended by '[-]'.
+    """Print a message to stdout, prepended by '[-]'.
 
     Note:
         If the application is not running in verbose mode, this function will
@@ -66,7 +65,7 @@ def info(msg):
 
 
 def print_level(log_function, fmt, level, *args):
-    """Prints a formatted message to stdout prepended by spaces. Useful for
+    """Print a formatted message to stdout prepended by spaces. Useful for
     printing hierarchical information, like bullet lists.
 
     Note:
@@ -101,13 +100,13 @@ def print_level(log_function, fmt, level, *args):
 
 
 def print_fatal_results(results, level=0):
-    """Prints fatal errors that occurred during validation runs.
+    """Print fatal errors that occurred during validation runs.
     """
     print_level(logger.critical, _RED + "[X] Fatal Error: %s", level, results.error)
 
 
 def print_schema_results(results, level=0):
-    """Prints JSON Schema validation errors to stdout.
+    """Print JSON Schema validation errors to stdout.
 
     Args:
         results: An instance of ObjectValidationResults.
@@ -119,7 +118,7 @@ def print_schema_results(results, level=0):
 
 
 def print_warning_results(results, level=0):
-    """Prints warning messages found during validation.
+    """Print warning messages found during validation.
     """
     marker = _YELLOW + "[!] "
 
@@ -128,7 +127,7 @@ def print_warning_results(results, level=0):
 
 
 def print_horizontal_rule():
-    """Prints a horizontal rule.
+    """Print a horizontal rule.
 
     Note:
         If the application is running in "Silent Mode"
@@ -142,32 +141,72 @@ def print_horizontal_rule():
     logger.info("=" * 80)
 
 
+def print_results_header(identifier, is_valid):
+    """Print a header for the results of either a file or an object.
+
+    """
+    print_horizontal_rule()
+    print_level(logger.info, "[-] Results for: %s", 0, identifier)
+
+    if is_valid:
+        marker = _GREEN + "[+]"
+        verdict = "Valid"
+        log_func = logger.info
+    else:
+        marker = _RED + "[X]"
+        verdict = "Invalid"
+        log_func = logger.error
+    print_level(log_func, "%s STIX JSON: %s", 0, marker, verdict)
+
+
+def print_object_results(obj_result):
+    """Print the results of validating an object.
+
+    Args:
+        obj_result: An ObjectValidationResults instance.
+
+    """
+    print_results_header(obj_result.object_id, obj_result.is_valid)
+
+    if obj_result.warnings:
+        print_warning_results(obj_result, 1)
+    if obj_result.errors:
+        print_schema_results(obj_result, 1)
+
+
+def print_file_results(file_result):
+    """Print the results of validating a file.
+
+    Args:
+        file_result: A FileValidationResults instance.
+
+    """
+    print_results_header(file_result.filepath, file_result.is_valid)
+
+    for object_result in file_result.object_results:
+        if object_result.warnings:
+            print_warning_results(object_result, 1)
+        if object_result.errors:
+            print_schema_results(object_result, 1)
+
+    if file_result.fatal:
+        print_fatal_results(file_result.fatal, 1)
+
+
 def print_results(results):
-    """Prints `results` (the results of validation) to stdout.
+    """Print `results` (the results of validation) to stdout.
 
     Args:
-        results: A list of FileValidationResults instances.
+        results: A list of FileValidationResults or ObjectValidationResults
+                 instances.
 
     """
-    for file_result in sorted(results, key=operator.attrgetter("filepath")):
-        print_horizontal_rule()
-        print_level(logger.info, "[-] Results for: %s", 0, file_result.filepath)
-
-        if file_result.is_valid:
-            marker = _GREEN + "[+]"
-            verdict = "Valid"
-            log_func = logger.info
-        else:
-            marker = _RED + "[X]"
-            verdict = "Invalid"
-            log_func = logger.error
-        print_level(log_func, "%s STIX JSON: %s", 0, marker, verdict)
-
-        for object_result in file_result.object_results:
-            if object_result.warnings:
-                print_warning_results(object_result, 1)
-            if object_result.errors:
-                print_schema_results(object_result, 1)
-
-        if file_result.fatal:
-            print_fatal_results(file_result.fatal, 1)
+    if not isinstance(results, list):
+        results = [results]
+
+    for r in results:
+        try:
+            r.log()
+        except AttributeError:
+            raise ValueError('Argument to print_results() must be a list of '
+                             'FileValidationResults or ObjectValidationResults.')
diff --git a/stix2validator/schemas b/stix2validator/schemas
index 7373376..8f2448b 160000
--- a/stix2validator/schemas
+++ b/stix2validator/schemas
@@ -1,1 +1,1 @@
-Subproject commit 73733762141d642a92a28fcab6ad4734866d5309
+Subproject commit 8f2448bd97e458dba103bbcf5249837781e3b716
diff --git a/stix2validator/scripts/stix2_validator.py b/stix2validator/scripts/stix2_validator.py
index 63d6927..7148a47 100644
--- a/stix2validator/scripts/stix2_validator.py
+++ b/stix2validator/scripts/stix2_validator.py
@@ -10,6 +10,7 @@ import sys
 from stix2validator import (ValidationError, codes, output, parse_args,
                             print_results, run_validation)
 
+logging.basicConfig(stream=sys.stdout, level=logging.INFO, format='%(message)s')
 logger = logging.getLogger(__name__)
 
 
diff --git a/stix2validator/validator.py b/stix2validator/validator.py
index ba5df60..2e73c6e 100644
--- a/stix2validator/validator.py
+++ b/stix2validator/validator.py
@@ -175,6 +175,11 @@ class FileValidationResults(BaseResults):
         else:
             self._object_results = [object_results]
 
+    def log(self):
+        """Print (log) these file validation results.
+        """
+        output.print_file_results(self)
+
 
 class ObjectValidationResults(BaseResults):
     """Results of JSON schema validation for a single STIX object.
@@ -191,10 +196,12 @@ class ObjectValidationResults(BaseResults):
     Attributes:
         is_valid: ``True`` if the validation was successful and ``False``
             otherwise.
+        object_id: ID of the STIX object.
 
     """
-    def __init__(self, is_valid=False, errors=None, warnings=None):
+    def __init__(self, is_valid=False, object_id=None, errors=None, warnings=None):
         super(ObjectValidationResults, self).__init__(is_valid)
+        self.object_id = object_id
         self.errors = errors
         self.warnings = warnings
 
@@ -232,6 +239,11 @@ class ObjectValidationResults(BaseResults):
 
         return d
 
+    def log(self):
+        """Print (log) these file validation results.
+        """
+        output.print_object_results(self)
+
 
 class ValidationErrorResults(BaseResults):
     """Results of a failed validation due to a raised Exception.
@@ -370,23 +382,23 @@ def validate_parsed_json(obj_json, options=None):
         init_requests_cache(options.refresh_cache)
 
     results = None
-    try:
-        if validating_list:
-            # Doing it this way instead of using a comprehension means that
-            # initial validation results will be retained, even if a later
-            # exception aborts the sequence.
-            results = []
-            for obj in obj_json:
+    if validating_list:
+        results = []
+        for obj in obj_json:
+            try:
                 results.append(validate_instance(obj, options))
-        else:
+            except SchemaInvalidError as ex:
+                error_result = ObjectValidationResults(is_valid=False,
+                                                       object_id=obj.get('id', ''),
+                                                       errors=[str(ex)])
+                results.append(error_result)
+    else:
+        try:
             results = validate_instance(obj_json, options)
-
-    except SchemaInvalidError as ex:
-        error_result = ObjectValidationResults(is_valid=False,
-                                               errors=[str(ex)])
-        if validating_list:
-            results.append(error_result)
-        else:
+        except SchemaInvalidError as ex:
+            error_result = ObjectValidationResults(is_valid=False,
+                                                   object_id=obj_json.get('id', ''),
+                                                   errors=[str(ex)])
             results = error_result
 
     if not options.no_cache and options.clear_cache:
@@ -447,8 +459,9 @@ def validate_file(fn, options=None):
                "validation will be performed: {error}")
         output.info(msg.format(fn=fn, error=str(ex)))
 
-    file_results.is_valid = all(object_result.is_valid
-                                for object_result in file_results.object_results)
+    file_results.is_valid = (all(object_result.is_valid
+                                 for object_result in file_results.object_results)
+                             and not file_results.fatal)
 
     return file_results
 
@@ -708,5 +721,5 @@ def validate_instance(instance, options=None):
     else:
         valid = True
 
-    return ObjectValidationResults(is_valid=valid, errors=error_list,
-                                   warnings=warnings)
+    return ObjectValidationResults(is_valid=valid, object_id=instance.get('id', ''),
+                                   errors=error_list, warnings=warnings)


Test patch:
diff --git a/stix2validator/test/indicator_tests.py b/stix2validator/test/indicator_tests.py
index df31bae..9f33896 100644
--- a/stix2validator/test/indicator_tests.py
+++ b/stix2validator/test/indicator_tests.py
@@ -2,7 +2,7 @@ import copy
 import json
 
 from . import ValidatorTest
-from .. import validate_parsed_json, validate_string
+from .. import ValidationOptions, validate_parsed_json, validate_string
 
 VALID_INDICATOR = u"""
 {
@@ -19,6 +19,13 @@ VALID_INDICATOR = u"""
 }
 """
 
+ADDTNL_INVALID_SCHEMA = {
+    "type": "x-foo-bar",
+    "id": "x-type--353ed279-5f4f-4a79-bffc-b2e2ed08ea1f",
+    "created": "2016-04-06T20:03:48.000Z",
+    "modified": "2016-04-06T20:03:48.000Z",
+}
+
 
 class IndicatorTestCases(ValidatorTest):
     valid_indicator = json.loads(VALID_INDICATOR)
@@ -152,7 +159,7 @@ class IndicatorTestCases(ValidatorTest):
 
     def test_pattern_custom_object_prefix_lax(self):
         indicator = copy.deepcopy(self.valid_indicator)
-        indicator['pattern'] = """[x-foo":x_name = 'something']"""
+        indicator['pattern'] = """[x-foo:x_name = 'something']"""
         self.check_ignore(indicator, 'custom-prefix')
 
     def test_pattern_custom_property_prefix_strict(self):
@@ -202,10 +209,14 @@ class IndicatorTestCases(ValidatorTest):
         self.assertTrueWithOptions(new_obj, schema_dir=self.custom_schemas)
 
     def test_additional_schemas_custom_type_invalid_schema(self):
-        new_obj = {
-            "type": "x-foo-bar",
-            "id": "x-type--353ed279-5f4f-4a79-bffc-b2e2ed08ea1f",
-            "created": "2016-04-06T20:03:48.000Z",
-            "modified": "2016-04-06T20:03:48.000Z",
-        }
-        self.assertFalseWithOptions(new_obj, schema_dir=self.custom_schemas)
+        self.assertFalseWithOptions(ADDTNL_INVALID_SCHEMA, schema_dir=self.custom_schemas)
+
+    def test_validate_parsed_json_list_additional_invalid_schema(self):
+        indicator = copy.deepcopy(self.valid_indicator)
+        indicator['name'] = 'Foobar'
+        objects = [indicator, ADDTNL_INVALID_SCHEMA]
+
+        options = ValidationOptions(schema_dir=self.custom_schemas)
+        results = validate_parsed_json(objects, options)
+        assert results[0].is_valid
+        assert not results[1].is_valid
diff --git a/stix2validator/test/misc_tests.py b/stix2validator/test/misc_tests.py
index 9209652..d97582e 100644
--- a/stix2validator/test/misc_tests.py
+++ b/stix2validator/test/misc_tests.py
@@ -1,27 +1,128 @@
+from io import open
+import logging
 import os
+import re
 import sys
 
 import pytest
 
-from . import ValidatorTest
-from .. import ValidationOptions, run_validation
+from .. import (ValidationOptions, print_results, run_validation,
+                validate_file, validate_string)
 from .tool_tests import VALID_TOOL
 
+logging.basicConfig(stream=sys.stdout, level=logging.INFO, format='%(message)s')
+logger = logging.getLogger(__name__)
 
-class MiscTestCases(ValidatorTest):
+EXAMPLE = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                       '..', 'schemas', 'examples',
+                       'indicator-to-campaign-relationship.json')
+IDENTITY = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                        'test_examples', 'identity.json')
+IDENTITY_CUSTOM = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                               'test_examples', 'identity_custom.json')
+INVALID_BRACES = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                              'test_examples', 'invalid_braces.json')
+INVALID_COMMA = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                             'test_examples', 'invalid_comma.json')
+INVALID_IDENTITY = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                                'test_examples', 'invalid_identity.json')
+INVALID_TIMESTAMP = os.path.join(os.path.dirname(os.path.realpath(__file__)),
+                                 'test_examples', 'invalid_timestamp.json')
 
-    def test_run_validation(self):
-        inputfile = os.path.join(os.path.dirname(os.path.realpath(__file__)),
-                                 '..', 'schemas', 'examples',
-                                 'using-granular-markings.json')
-        options = ValidationOptions(files=[inputfile])
-        results = run_validation(options)
-        assert results[0].is_valid
 
-    def test_run_validation_nonexistent_file(self):
-        options = ValidationOptions(files='asdf.json')
-        with pytest.raises(SystemExit):
-            run_validation(options)
+def test_run_validation(caplog):
+    options = ValidationOptions(files=[EXAMPLE])
+    results = run_validation(options)
+    assert results[0].is_valid
+
+    print_results(results)
+    assert 'STIX JSON: Valid' in caplog.text
+
+
+def test_run_validation_nonexistent_file():
+    options = ValidationOptions(files='asdf.json')
+    with pytest.raises(SystemExit):
+        run_validation(options)
+
+
+def test_run_validation_silent(caplog):
+    options = ValidationOptions(files=[EXAMPLE], silent=True)
+    results = run_validation(options)
+    print_results(results)
+    assert caplog.text == ''
+
+
+def test_validate_file(caplog):
+    results = validate_file(EXAMPLE)
+    assert results.is_valid
+
+    print_results(results)
+    assert 'STIX JSON: Valid' in caplog.text
+
+
+def test_validate_file_warning(caplog):
+    results = validate_file(IDENTITY_CUSTOM)
+    assert results.is_valid
+
+    print_results(results)
+    assert re.search("Custom property .+ should have a type that starts with 'x_'", caplog.text)
+
+
+def test_validate_file_invalid_brace(caplog):
+    results = validate_file(INVALID_BRACES)
+    assert not results.is_valid
+
+    print_results(results)
+    assert 'Fatal Error: Invalid JSON input' in caplog.text
+
+
+def test_validate_file_invalid_comma(caplog):
+    results = validate_file(INVALID_COMMA)
+    assert not results.is_valid
+
+    print_results(results)
+    assert 'Fatal Error: Expecting property name' in caplog.text
+
+
+def test_validate_file_invalid_missing_modified(caplog):
+    results = validate_file(INVALID_IDENTITY)
+    assert not results.is_valid
+
+    print_results(results)
+    assert "'modified' is a required property" in caplog.text
+
+
+def test_validate_string(caplog):
+    with open(IDENTITY, encoding='utf-8') as f:
+        results = validate_string(f.read())
+    assert results.is_valid
+
+    print_results(results)
+    assert 'STIX JSON: Valid' in caplog.text
+
+
+def test_validate_string_warning(caplog):
+    with open(IDENTITY_CUSTOM, encoding='utf-8') as f:
+        results = validate_string(f.read())
+    assert results.is_valid
+
+    print_results(results)
+    assert re.search("Custom property .+ should have a type that starts with 'x_'", caplog.text)
+
+
+def test_validate_string_invalid_timestamp(caplog):
+    with open(INVALID_TIMESTAMP, encoding='utf-8') as f:
+        results = validate_string(f.read())
+    assert not results.is_valid
+
+    print_results(results)
+    assert re.search("'modified' .+ must be later or equal to 'created'", caplog.text)
+
+
+def test_print_results_invalid_parameter():
+    with pytest.raises(ValueError) as excinfo:
+        print_results('these results are valid')
+    assert 'Argument to print_results() must be' in str(excinfo)
 
 
 def test_run_validation_stdin(monkeypatch):
diff --git a/stix2validator/test/test_examples/identity.json b/stix2validator/test/test_examples/identity.json
new file mode 100644
index 0000000..91a76c5
--- /dev/null
+++ b/stix2validator/test/test_examples/identity.json
@@ -0,0 +1,8 @@
+{
+  "type": "identity",
+  "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+  "created": "2016-08-08T15:50:10.983Z",
+  "modified": "2016-08-08T15:50:10.983Z",
+  "name": "Franistan Intelligence",
+  "identity_class": "organization"
+}
diff --git a/stix2validator/test/test_examples/identity_custom.json b/stix2validator/test/test_examples/identity_custom.json
new file mode 100644
index 0000000..0101f7e
--- /dev/null
+++ b/stix2validator/test/test_examples/identity_custom.json
@@ -0,0 +1,16 @@
+{
+  "type": "bundle",
+  "id": "bundle--d6a999f2-849c-4d1b-aba4-4445c4444444",
+  "spec_version": "2.0",
+  "objects": [
+    {
+      "type": "identity",
+      "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+      "created": "2016-08-08T15:50:10.983Z",
+      "modified": "2016-08-08T15:50:10.983Z",
+      "name": "Franistan Intelligence",
+      "identity_class": "organization",
+      "foo": "bar"
+    }
+  ]
+}
diff --git a/stix2validator/test/test_examples/identity_warning.json b/stix2validator/test/test_examples/identity_warning.json
new file mode 100644
index 0000000..91a76c5
--- /dev/null
+++ b/stix2validator/test/test_examples/identity_warning.json
@@ -0,0 +1,8 @@
+{
+  "type": "identity",
+  "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+  "created": "2016-08-08T15:50:10.983Z",
+  "modified": "2016-08-08T15:50:10.983Z",
+  "name": "Franistan Intelligence",
+  "identity_class": "organization"
+}
diff --git a/stix2validator/test/test_examples/invalid_braces.json b/stix2validator/test/test_examples/invalid_braces.json
new file mode 100644
index 0000000..36e92c4
--- /dev/null
+++ b/stix2validator/test/test_examples/invalid_braces.json
@@ -0,0 +1,8 @@
+<{
+  "type": "identity",
+  "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+  "created": "2016-08-08T15:50:10.983Z",
+  "modified": "2016-08-08T15:50:10.983Z",
+  "name": "Franistan Intelligence",
+  "identity_class": "organization"
+}>
diff --git a/stix2validator/test/test_examples/invalid_comma.json b/stix2validator/test/test_examples/invalid_comma.json
new file mode 100644
index 0000000..6c0aaeb
--- /dev/null
+++ b/stix2validator/test/test_examples/invalid_comma.json
@@ -0,0 +1,8 @@
+{
+  "type": "identity",
+  "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+  "created": "2016-08-08T15:50:10.983Z",
+  "modified": "2016-08-08T15:50:10.983Z",
+  "name": "Franistan Intelligence",
+  "identity_class": "organization",
+}
diff --git a/stix2validator/test/test_examples/invalid_identity.json b/stix2validator/test/test_examples/invalid_identity.json
new file mode 100644
index 0000000..11d11ac
--- /dev/null
+++ b/stix2validator/test/test_examples/invalid_identity.json
@@ -0,0 +1,7 @@
+{
+  "type": "identity",
+  "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+  "created": "2016-08-08T15:50:10.983Z",
+  "name": "Franistan Intelligence",
+  "identity_class": "organization"
+}
diff --git a/stix2validator/test/test_examples/invalid_timestamp.json b/stix2validator/test/test_examples/invalid_timestamp.json
new file mode 100644
index 0000000..b4d379f
--- /dev/null
+++ b/stix2validator/test/test_examples/invalid_timestamp.json
@@ -0,0 +1,8 @@
+{
+  "type": "identity",
+  "id": "identity--8c6af861-7b20-41ef-9b59-6344fd872a8f",
+  "created": "2016-08-08T15:50:10.983Z",
+  "modified": "2015-08-08T15:50:10.983Z",
+  "name": "Franistan Intelligence",
+  "identity_class": "organization"
+}