Repository: bitcrowd/chromic_pdf
Pull request #172 (2022-10-18 09:19:43)

Include inspected protocol in timeout error
This patch adds an `Inspect` implementation for `ChromicPDF.Protocol` that redacts any potentially sensitive data, leaving merely ChromicPDF internals and options. Next, the inspected protocol is included in the timeout error in `Channel.run_protocol/3`, as this is the error a lot of people run into in various situations: boot time, teardown, etc.

Relates to #160 
Relates to #171 


Patch:
diff --git a/.circleci/config.yml b/.circleci/config.yml
index 7f1adaf..ded5f45 100644
--- a/.circleci/config.yml
+++ b/.circleci/config.yml
@@ -16,21 +16,21 @@ jobs:
       - run: mix local.rebar --force
       - restore_cache:
           keys:
-            - v3-deps-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
-            - v3-deps-cache-{{ .Branch }}
-            - v3-deps-cache
+            - v4-deps-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
+            - v4-deps-cache-{{ .Branch }}
+            - v4-deps-cache
       - run: mix deps.get
       - save_cache:
-          key: v3-deps-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
+          key: v4-deps-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
           paths: deps
       - save_cache:
-          key: v3-deps-cache-{{ .Branch }}
+          key: v4-deps-cache-{{ .Branch }}
           paths: deps
       - save_cache:
-          key: v3-deps-cache
+          key: v4-deps-cache
           paths: deps
       - save_cache:
-          key: v3-repo-cache-setup-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-setup-{{ .Environment.CIRCLE_SHA1 }}
           paths:
             - ~/.mix
             - ~/repo
@@ -41,38 +41,38 @@ jobs:
       MIX_ENV: test
     steps:
       - restore_cache:
-          key: v3-repo-cache-setup-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-setup-{{ .Environment.CIRCLE_SHA1 }}
       - restore_cache:
           keys:
-            - v3-build-cache-test-{{ .Branch }}
-            - v3-build-cache-test
+            - v4-build-cache-test-{{ .Branch }}
+            - v4-build-cache-test
       - restore_cache:
           keys:
-            - v3-plt-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
-            - v3-plt-cache-{{ .Branch }}
-            - v3-plt-cache
+            - v4-plt-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
+            - v4-plt-cache-{{ .Branch }}
+            - v4-plt-cache
       - run: mix compile
       - run: mix dialyzer --plt
       - save_cache:
-          key: v3-build-cache-test-{{ .Branch }}
+          key: v4-build-cache-test-{{ .Branch }}
           paths: _build/test
       - save_cache:
-          key: v3-build-cache-test
+          key: v4-build-cache-test
           paths: _build/test
       - save_cache:
-          key: v3-plt-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
+          key: v4-plt-cache-{{ .Branch }}-{{ checksum "mix.lock" }}
           paths:
             - .plts
       - save_cache:
-          key: v3-plt-cache-{{ .Branch }}
+          key: v4-plt-cache-{{ .Branch }}
           paths:
             - .plts
       - save_cache:
-          key: v3-plt-cache
+          key: v4-plt-cache
           paths:
             - .plts
       - save_cache:
-          key: v3-repo-cache-test-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-test-{{ .Environment.CIRCLE_SHA1 }}
           paths:
             - ~/.mix
             - ~/repo
@@ -84,20 +84,20 @@ jobs:
     steps:
       - restore_cache:
           keys:
-            - v3-repo-cache-setup-{{ .Environment.CIRCLE_SHA1 }}
+            - v4-repo-cache-setup-{{ .Environment.CIRCLE_SHA1 }}
       - restore_cache:
           keys:
-            - v3-build-cache-integration-{{ .Branch }}
-            - v3-build-cache-integration
+            - v4-build-cache-integration-{{ .Branch }}
+            - v4-build-cache-integration
       - run: mix compile
       - save_cache:
-          key: v3-build-cache-integration-{{ .Branch }}
+          key: v4-build-cache-integration-{{ .Branch }}
           paths: _build/integration
       - save_cache:
-          key: v3-build-cache-integration
+          key: v4-build-cache-integration
           paths: _build/integration
       - save_cache:
-          key: v3-repo-cache-integration-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-integration-{{ .Environment.CIRCLE_SHA1 }}
           paths:
             - ~/.mix
             - ~/repo
@@ -108,7 +108,7 @@ jobs:
       MIX_ENV: test
     steps:
       - restore_cache:
-          key: v3-repo-cache-test-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-test-{{ .Environment.CIRCLE_SHA1 }}
       - run:
           name: Run Linter
           command: mix lint
@@ -119,7 +119,7 @@ jobs:
       MIX_ENV: test
     steps:
       - restore_cache:
-          key: v3-repo-cache-test-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-test-{{ .Environment.CIRCLE_SHA1 }}
       - run:
           name: Run Unit Tests
           command: mix test
@@ -132,7 +132,7 @@ jobs:
       MIX_ENV: integration
     steps:
       - restore_cache:
-          key: v3-repo-cache-integration-{{ .Environment.CIRCLE_SHA1 }}
+          key: v4-repo-cache-integration-{{ .Environment.CIRCLE_SHA1 }}
       - run:
           name: Run Integration Tests
           command: mix test
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 632b224..13e8622 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -1,3 +1,9 @@
+## Unreleased
+
+### Changed
+
+- Included the inspected `ChromicPDF.Protocol` in the timeout exception to improve debugging.
+
 ## [1.3.0] - 2022-09-27
 
 ### Added
diff --git a/lib/chromic_pdf/pdf/browser/channel.ex b/lib/chromic_pdf/pdf/browser/channel.ex
index 1e6a48b..7b743c2 100644
--- a/lib/chromic_pdf/pdf/browser/channel.ex
+++ b/lib/chromic_pdf/pdf/browser/channel.ex
@@ -22,7 +22,7 @@ defmodule ChromicPDF.Browser.Channel do
   def run_protocol(pid, %Protocol{} = protocol, timeout) do
     GenServer.call(pid, {:run_protocol, protocol}, timeout)
   catch
-    :exit, {:timeout, {GenServer, :call, [_pid, {:run_protocol, _protocol}, _timeout]}} ->
+    :exit, {:timeout, {GenServer, :call, [_pid, {:run_protocol, protocol}, _timeout]}} ->
       raise("""
       Timeout in Channel.run_protocol/3!
 
@@ -35,6 +35,12 @@ defmodule ChromicPDF.Browser.Channel do
 
       If you are *not* printing large PDFs but your print jobs still time out, this is likely a
       bug in ChromicPDF. Please open an issue on the issue tracker.
+
+      ---
+
+      Current protocol:
+
+      #{inspect(protocol, pretty: true)}
       """)
   end
 
diff --git a/lib/chromic_pdf/pdf/protocol.ex b/lib/chromic_pdf/pdf/protocol.ex
index 550a251..6057feb 100644
--- a/lib/chromic_pdf/pdf/protocol.ex
+++ b/lib/chromic_pdf/pdf/protocol.ex
@@ -138,4 +138,73 @@ defmodule ChromicPDF.Protocol do
       """)
     end
   end
+
+  defimpl Inspect do
+    @filtered "[FILTERED]"
+
+    @allowed_values %{
+      result_fun: true,
+      steps: true,
+      state: %{
+        :capture_screenshot => %{
+          "format" => true,
+          "quality" => true,
+          "clip" => true,
+          "fromSurface" => true,
+          "captureBeyondViewport" => true
+        },
+        :print_to_pdf => %{
+          "landscape" => true,
+          "displayHeaderFooter" => true,
+          "printBackground" => true,
+          "scale" => true,
+          "paperWidth" => true,
+          "paperHeight" => true,
+          "marginTop" => true,
+          "marginBottom" => true,
+          "marginLeft" => true,
+          "marginRight" => true,
+          "pageRanges" => true,
+          "preferCSSPageSize" => true
+        },
+        :source_type => true,
+        "sessionId" => true,
+        :wait_for => true,
+        :evaluate => true,
+        :size => true,
+        :init_timeout => true,
+        :timeout => true,
+        :offline => true,
+        :disable_scripts => true,
+        :max_session_uses => true,
+        :session_pool => true,
+        :no_sandbox => true,
+        :discard_stderr => true,
+        :chrome_args => true,
+        :chrome_executable => true,
+        :ignore_certificate_errors => true,
+        :ghostscript_pool => true,
+        :on_demand => true,
+        :__protocol__ => true
+      }
+    }
+
+    def inspect(%ChromicPDF.Protocol{} = protocol, opts) do
+      protocol
+      |> Map.from_struct()
+      |> filter(@allowed_values)
+      |> then(fn map -> struct!(ChromicPDF.Protocol, map) end)
+      |> Inspect.Any.inspect(opts)
+    end
+
+    defp filter(map, allowed) when is_map(map) and is_map(allowed) do
+      Map.new(map, fn {key, value} ->
+        case Map.get(allowed, key) do
+          nil -> {key, @filtered}
+          true -> {key, value}
+          nested when is_map(nested) -> {key, filter(value, nested)}
+        end
+      end)
+    end
+  end
 end
diff --git a/lib/chromic_pdf/pdf/protocol_macros.ex b/lib/chromic_pdf/pdf/protocol_macros.ex
index 1c7ad77..5e4aa6d 100644
--- a/lib/chromic_pdf/pdf/protocol_macros.ex
+++ b/lib/chromic_pdf/pdf/protocol_macros.ex
@@ -24,7 +24,7 @@ defmodule ChromicPDF.ProtocolMacros do
       def new(opts \\ []) do
         Protocol.new(
           build_steps(opts),
-          Enum.into(opts, %{})
+          initial_state(opts)
         )
       end
 
@@ -32,10 +32,22 @@ defmodule ChromicPDF.ProtocolMacros do
       def new(session_id, opts) do
         Protocol.new(
           build_steps(opts),
-          opts |> Enum.into(%{}) |> Map.put("sessionId", session_id)
+          initial_state(session_id, opts)
         )
       end
 
+      defp initial_state(opts) do
+        opts
+        |> Enum.into(%{})
+        |> Map.put(:__protocol__, __MODULE__)
+      end
+
+      defp initial_state(session_id, opts) do
+        opts
+        |> initial_state()
+        |> Map.put("sessionId", session_id)
+      end
+
       defp build_steps(opts) do
         @steps
         |> Enum.reverse()
diff --git a/lib/chromic_pdf/supervisor.ex b/lib/chromic_pdf/supervisor.ex
index 4c86d7b..c7f88a6 100644
--- a/lib/chromic_pdf/supervisor.ex
+++ b/lib/chromic_pdf/supervisor.ex
@@ -209,6 +209,7 @@ defmodule ChromicPDF.Supervisor do
               {:size, non_neg_integer()}
               | {:init_timeout, timeout()}
               | {:timeout, timeout()}
+
       @type ghostscript_pool_option :: {:size, non_neg_integer()}
 
       @type global_option ::


Test patch:
diff --git a/test/integration/pdf_generation_test.exs b/test/integration/pdf_generation_test.exs
index ee2b213..cb1c423 100644
--- a/test/integration/pdf_generation_test.exs
+++ b/test/integration/pdf_generation_test.exs
@@ -346,8 +346,9 @@ defmodule ChromicPDF.PDFGenerationTest do
           :timer.sleep(10)
         end)
 
-      assert err =~ "(RuntimeError) Timeout in Channel.run_protocol"
+      assert err =~ "Timeout in Channel.run_protocol"
       assert err =~ "within the configured\n1 milliseconds"
+      assert err =~ "%ChromicPDF.Protocol{"
     end
   end
 
diff --git a/test/unit/chromic_pdf/pdf/protocol_test.exs b/test/unit/chromic_pdf/pdf/protocol_test.exs
new file mode 100644
index 0000000..4f53d8f
--- /dev/null
+++ b/test/unit/chromic_pdf/pdf/protocol_test.exs
@@ -0,0 +1,96 @@
+# SPDX-License-Identifier: Apache-2.0
+
+defmodule ChromicPDF.ProtocolTest do
+  use ExUnit.Case, async: true
+  alias ChromicPDF.PrintToPDF
+
+  describe "Inspect.ChromicPDF.Protocol" do
+    test "looks reasonable and does not leak client data" do
+      opts = [
+        source_type: "html",
+        source: "<html>...",
+        output: "/some/path",
+        capture_screenshot: %{
+          "format" => "jpeg",
+          "quality" => 100,
+          "clip" => "some-viewport",
+          "fromSurface" => true,
+          "captureBeyondViewport" => true
+        },
+        print_to_pdf: %{
+          "landscape" => true,
+          "displayHeaderFooter" => true,
+          "printBackground" => true,
+          "scale" => 1,
+          "paperWidth" => 1,
+          "paperHeight" => 1,
+          "marginTop" => 1,
+          "marginBottom" => 1,
+          "marginLeft" => 1,
+          "marginRight" => 1,
+          "pageRanges" => "1-2",
+          "preferCSSPageSize" => true
+        },
+        wait_for: %{selector: "foo", attribute: "bar"},
+        evaluate: "someFunction();",
+        size: 1,
+        init_timeout: 1,
+        timeout: 1,
+        offline: true,
+        disable_scripts: true,
+        max_session_uses: 1,
+        session_pool: 1,
+        no_sandbox: true,
+        discard_stderr: true,
+        chrome_args: "some-args",
+        chrome_executable: "chromium",
+        ignore_certificate_errors: true,
+        ghostscript_pool: 1,
+        on_demand: true
+      ]
+
+      inspected = inspect(PrintToPDF.new("12345", opts))
+
+      assert inspected =~ ~s(result_fun: nil)
+      assert inspected =~ ~s(:__protocol__ => ChromicPDF.PrintToPDF)
+      assert inspected =~ ~s("captureBeyondViewport" => true)
+      assert inspected =~ ~s("clip" => "some-viewport")
+      assert inspected =~ ~s("format" => "jpeg")
+      assert inspected =~ ~s("fromSurface" => true)
+      assert inspected =~ ~s("quality" => 10)
+      assert inspected =~ ~s(:chrome_args => "some-args")
+      assert inspected =~ ~s(:chrome_executable => "chromium")
+      assert inspected =~ ~s(:disable_scripts => true)
+      assert inspected =~ ~s(:discard_stderr => true)
+      assert inspected =~ ~s(:evaluate => "someFunction(\);")
+      assert inspected =~ ~s(:ghostscript_pool => 1)
+      assert inspected =~ ~s(:ignore_certificate_errors => true)
+      assert inspected =~ ~s(:init_timeout => 1)
+      assert inspected =~ ~s(:max_session_uses => 1)
+      assert inspected =~ ~s(:no_sandbox => true)
+      assert inspected =~ ~s(:offline => true)
+      assert inspected =~ ~s(:on_demand => true)
+      assert inspected =~ ~s(:output => "[FILTERED]")
+      assert inspected =~ ~s("displayHeaderFooter" => true)
+      assert inspected =~ ~s("landscape" => true)
+      assert inspected =~ ~s("marginBottom" => 1)
+      assert inspected =~ ~s("marginLeft" => 1)
+      assert inspected =~ ~s("marginRight" => 1)
+      assert inspected =~ ~s("marginTop" => 1)
+      assert inspected =~ ~s("pageRanges" => "1-2")
+      assert inspected =~ ~s("paperHeight" => 1)
+      assert inspected =~ ~s("paperWidth" => 1)
+      assert inspected =~ ~s("preferCSSPageSize" => true)
+      assert inspected =~ ~s("printBackground" => true)
+      assert inspected =~ ~s("scale" => )
+      assert inspected =~ ~s(:session_pool => 1)
+      assert inspected =~ ~s(:size => 1)
+      assert inspected =~ ~s(:source => "[FILTERED]")
+      assert inspected =~ ~s(:source_type => "html")
+      assert inspected =~ ~s(:timeout => 1)
+      assert inspected =~ ~s(:wait_for => %{attribute: "bar", selector: "foo"})
+      assert inspected =~ ~s("sessionId" => "12345)
+      assert inspected =~ "steps"
+    end
+  end
+end