Repository: dbt-labs/dbt-core
Pull request: fix an RPC hang when enddocs tags were missing (#2066)
Fix #2066 

Fix an issue with rendering the output of a failed jinja block parsing pass where dbt would raise an exception while raising an exception, due to `str(exc)` failing by implementing a TODO I wrote a long time ago...

Added tests so we don't experience this again, hopefully.

Problem statement:
dbt server fails to reload on HUP if docs block is missing enddocs tag
### Describe the bug
When running the dbt server, invalid jinja code can cause the server to get stuck in a "compiling" state. This does _not_ require partial parsing to be enabled.

### Steps To Reproduce
1. Create a file, `models/docs.md` with the following contents:
```
{% docs abc%} hi {% enddocs %}
```
2. run `dbt rpc`
3. Modify `models/docs.md` to remove the `enddocs` tag
4. Send the dbt server process a SIGHUP signal
5. Observe that the `status` method on the server returns a `compiling` state

If you try to run a `dbt compile` (using dbt v0.15.1 or dev/0.15.2) with the same malformed docs block, you will see:

```
Running with dbt=0.15.2-a1
Encountered an error:
Traceback (most recent call last):
  File "/Users/drew/fishtown/dbt/core/dbt/main.py", line 80, in main
    results, succeeded = handle_and_check(args)
  File "/Users/drew/fishtown/dbt/core/dbt/main.py", line 158, in handle_and_check
    task, res = run_from_args(parsed)
  File "/Users/drew/fishtown/dbt/core/dbt/main.py", line 210, in run_from_args
    results = task.run()
  File "/Users/drew/fishtown/dbt/core/dbt/task/runnable.py", line 300, in run
    self._runtime_initialize()
  File "/Users/drew/fishtown/dbt/core/dbt/task/runnable.py", line 81, in _runtime_initialize
    super()._runtime_initialize()
  File "/Users/drew/fishtown/dbt/core/dbt/task/runnable.py", line 54, in _runtime_initialize
    self.load_manifest()
  File "/Users/drew/fishtown/dbt/core/dbt/task/runnable.py", line 46, in load_manifest
    self.manifest = get_full_manifest(self.config)
  File "/Users/drew/fishtown/dbt/core/dbt/perf_utils.py", line 23, in get_full_manifest
    return load_manifest(config, internal, set_header)
  File "/Users/drew/fishtown/dbt/core/dbt/parser/manifest.py", line 441, in load_manifest
    return ManifestLoader.load_all(config, internal_manifest, macro_hook)
  File "/Users/drew/fishtown/dbt/core/dbt/parser/manifest.py", line 329, in load_all
    loader.load(internal_manifest=internal_manifest)
  File "/Users/drew/fishtown/dbt/core/dbt/parser/manifest.py", line 200, in load
    self.parse_project(project, macro_manifest, old_results)
  File "/Users/drew/fishtown/dbt/core/dbt/parser/manifest.py", line 174, in parse_project
    self.parse_with_cache(path, parser, old_results)
  File "/Users/drew/fishtown/dbt/core/dbt/parser/manifest.py", line 133, in parse_with_cache
    parser.parse_file(block)
  File "/Users/drew/fishtown/dbt/core/dbt/parser/docs.py", line 90, in parse_file
    for block in searcher:
  File "/Users/drew/fishtown/dbt/core/dbt/parser/search.py", line 125, in __iter__
    for block in self.extract_blocks(entry):
  File "/Users/drew/fishtown/dbt/core/dbt/parser/search.py", line 110, in extract_blocks
    collect_raw_data=False
  File "/Users/drew/fishtown/dbt/core/dbt/clients/jinja.py", line 399, in extract_toplevel_blocks
    collect_raw_data=collect_raw_data
  File "/Users/drew/fishtown/dbt/core/dbt/clients/_jinja_blocks.py", line 371, in lex_for_blocks
    collect_raw_data=collect_raw_data))
  File "/Users/drew/fishtown/dbt/core/dbt/clients/_jinja_blocks.py", line 362, in find_blocks
    ).format(self.current))
  File "/Users/drew/fishtown/dbt/core/dbt/exceptions.py", line 357, in raise_compiler_error
    raise CompilationException(msg, node)
dbt.exceptions.CompilationException: <exception str() failed>

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/drew/fishtown/dbt/env/bin/dbt", line 7, in <module>
    exec(compile(f.read(), __file__, 'exec'))
  File "/Users/drew/fishtown/dbt/core/scripts/dbt", line 7, in <module>
    dbt.main.main(sys.argv[1:])
  File "/Users/drew/fishtown/dbt/core/dbt/main.py", line 96, in main
    logger.warning(str(e))
  File "/Users/drew/fishtown/dbt/core/dbt/exceptions.py", line 99, in __str__
    node_string = " in {}".format(self.node_to_string(self.node))
  File "/Users/drew/fishtown/dbt/core/dbt/exceptions.py", line 66, in node_to_string
    node.resource_type,
AttributeError: 'NotImplementedType' object has no attribute 'resource_type'
```

My guess is that this that the exception raised during exception handling is the culprit here, but I'm not certain of that.

### Expected behavior
I would expect the server to be in an "error" state after HUPing the server with invalid dbt code.

**The output of `dbt --version`:**
Reproduced with `v0.15.1` and `dev/0.15.2`

**The operating system you're using:** macOS

Hints from issue discussion:

Commit message: fix an RPC hang when enddocs tags were missing, add tests

Patch to review:
diff --git a/core/dbt/clients/_jinja_blocks.py b/core/dbt/clients/_jinja_blocks.py
index 8d9ce891bdc..34778b9f28b 100644
--- a/core/dbt/clients/_jinja_blocks.py
+++ b/core/dbt/clients/_jinja_blocks.py
@@ -357,8 +357,8 @@ def find_blocks(self, allowed_blocks=None, collect_raw_data=True):
 
         if self.current:
             dbt.exceptions.raise_compiler_error((
-                'Reached EOF without finding a close block for '
-                '{0.block_type_name} (from {0.end})'
+                'Reached EOF without finding a close tag for '
+                '{0.block_type_name} (searched from position {0.end})'
             ).format(self.current))
 
         if collect_raw_data:
diff --git a/core/dbt/exceptions.py b/core/dbt/exceptions.py
index 50eb7b4d438..61a0af98f5b 100644
--- a/core/dbt/exceptions.py
+++ b/core/dbt/exceptions.py
@@ -66,6 +66,12 @@ def node_to_string(self, node):
                 node.resource_type,
                 node.original_file_path
             )
+
+        if hasattr(node, 'contents'):
+            # handle FileBlocks. They aren't really nodes but we want to render
+            # out the path we know at least. This indicates an error during
+            # block parsing.
+            return '{}'.format(node.path.original_file_path)
         return "{} {} ({})".format(
             node.resource_type,
             node.name,
diff --git a/core/dbt/parser/search.py b/core/dbt/parser/search.py
index 08384d7bd2d..a5d8b5fe441 100644
--- a/core/dbt/parser/search.py
+++ b/core/dbt/parser/search.py
@@ -116,8 +116,7 @@ def extract_blocks(self, source_file: FileBlock) -> Iterable[BlockTag]:
 
         except CompilationException as exc:
             if exc.node is None:
-                # TODO(jeb): attach info about resource type/file path here
-                exc.node = NotImplemented
+                exc.node = source_file
             raise
 
     def __iter__(self) -> Iterator[BlockSearchResult]:
diff --git a/test/rpc/test_base.py b/test/rpc/test_base.py
index 7a061f5a74e..cc7d910a7ca 100644
--- a/test/rpc/test_base.py
+++ b/test/rpc/test_base.py
@@ -790,3 +790,42 @@ def test_source_freshness(
         pass_results = querier.async_wait_for_result(querier.cli_args('source snapshot-freshness --select test_source.test_table'))
         assert len(pass_results['results']) == 1
         assert pass_results['results'][0]['status'] == 'pass'
+
+
+def test_missing_tag_sighup(
+    project_root, profiles_root, postgres_profile, unique_schema
+):
+    project = ProjectDefinition(
+        models={
+            'my_docs.md': '{% docs asdf %}have a close tag{% enddocs %}',
+        },
+    )
+    querier_ctx = get_querier(
+        project_def=project,
+        project_dir=project_root,
+        profiles_dir=profiles_root,
+        schema=unique_schema,
+        test_kwargs={},
+    )
+    with querier_ctx as querier:
+        # everything is fine
+        assert querier.wait_for_status('ready') is True
+
+        # write a junk docs file
+        project.models['my_docs.md'] = '{% docs asdf %}do not have a close tag'
+        project.write_models(project_root, remove=True)
+
+        querier.sighup()
+
+        assert querier.wait_for_status('error') is True
+        result = querier.is_result(querier.status())
+        assert 'error' in result
+        assert 'message' in result['error']
+        assert 'without finding a close tag for docs' in result['error']['message']
+
+        project.models['my_docs.md'] = '{% docs asdf %}have a close tag again{% enddocs %}'
+        project.write_models(project_root, remove=True)
+
+        querier.sighup()
+
+        assert querier.wait_for_status('ready') is True
diff --git a/test/rpc/util.py b/test/rpc/util.py
index 8f8a9dd4772..0c550be1dcf 100644
--- a/test/rpc/util.py
+++ b/test/rpc/util.py
@@ -108,6 +108,9 @@ class Querier:
     def __init__(self, server: ServerProcess):
         self.server = server
 
+    def sighup(self):
+        os.kill(self.server.pid, signal.SIGHUP)
+
     def build_request_data(self, method, params, request_id):
         return {
             'jsonrpc': '2.0',
@@ -130,6 +133,14 @@ def request(self, method, params=None, request_id=1):
     def status(self, request_id: int = 1):
         return self.request(method='status', request_id=request_id)
 
+    def wait_for_status(self, expected, times=30) -> bool:
+        for _ in range(times):
+            time.sleep(0.5)
+            status = self.is_result(self.status())
+            if status['state'] == expected:
+                return True
+        return False
+
     def ps(self, active=True, completed=False, request_id=1):
         params = {}
         if active is not None:
@@ -465,7 +476,7 @@ def __init__(
 
     def _write_recursive(self, path, inputs):
         for name, value in inputs.items():
-            if name.endswith('.sql') or name.endswith('.csv'):
+            if name.endswith('.sql') or name.endswith('.csv') or name.endswith('.md'):
                 path.join(name).write(value)
             elif name.endswith('.yml'):
                 if isinstance(value, str):


Code review comments:
diff_hunk: @@ -357,8 +357,8 @@ def find_blocks(self, allowed_blocks=None, collect_raw_data=True):
 
         if self.current:
             dbt.exceptions.raise_compiler_error((
-                'Reached EOF without finding a close block for '
-                '{0.block_type_name} (from {0.end})'
+                'Reached EOF without finding a close tag for '
+                '{0.block_type_name} (searched from position {0.end})'
path: core/dbt/clients/_jinja_blocks.py
text: @user1:
Do you happen to know if we get a line number in `self.current` here? If so, I think that would be better than a character position. If we can't easily get a line number (what line number would it even be? The end tag doesn't exist...?), then I think we can just delete the text from `(search from ...` onwards.

@author:
The line number would be the line where we _started_ looking for the end tag:
```
$ cat models/docs.md
{% docs some_doc %}
some stuff
{% enddocs %}

{% docs my_doc %}
Check out my super cool doc() documentation
$ dbt compile
Running with dbt=0.15.2-a1
Encountered an error:
Compilation Error in models/docs.md
  Reached EOF without finding a close tag for docs (searched from line 5)
```