Harden the hledger subprocess and report failures

app/controllers/hledger/reports_controller.rb

@@ -50,10 +50,16 @@ module ::Hledger
         on_failed_contract do |contract|
           render_json_error(contract.errors.full_messages, status: 422)
         end
-        on_exceptions(Hledger::UnavailableError) do
+        on_exceptions(Hledger::UnavailableError) do |error|
+          log_failure(error)
           render_json_error(I18n.t("hledger.errors.unavailable"), status: 503)
         end
-        on_exceptions(Hledger::Error) do
+        on_exceptions(Hledger::OutputLimitError) do |error|
+          log_failure(error)
+          render_json_error(I18n.t("hledger.errors.output_too_large"), status: 422)
+        end
+        on_exceptions(Hledger::Error) do |error|
+          log_failure(error)
           render_json_error(I18n.t("hledger.errors.execution"), status: 422)
         end
         on_failure { render_json_error(I18n.t("hledger.errors.generic"), status: 422) }
@@ -107,5 +113,12 @@ module ::Hledger
 
       render_json_error(I18n.t(key), status: error == :none ? 404 : 422)
     end
+
+    def log_failure(error)
+      Rails.logger.warn(
+        "hledger report failed: report=#{params[:report_type]} topic=#{@topic&.id} " \
+          "user=#{current_user&.id} error=#{error.class} detail=#{error.message.to_s.truncate(500)}",
+      )
+    end
   end
 end

config/locales/server.en.yml

@@ -5,12 +5,14 @@ en:
     hledger_max_journal_bytes: "Maximum size of an hledger journal in bytes"
     hledger_timeout_seconds: "Maximum number of seconds an hledger command may run"
     hledger_max_output_bytes: "Maximum number of bytes captured from hledger output"
+    hledger_memory_limit_mb: "Maximum memory in megabytes the hledger process may use; set to 0 to disable the limit"
   hledger:
     errors:
       unsupported_report: "Unsupported report type."
       invalid_date: "Invalid date; expected YYYY-MM-DD."
       unavailable: "hledger is not available on this server."
       execution: "hledger could not generate the report."
+      output_too_large: "The report is too large to generate."
       generic: "The report could not be generated."
       journal:
         none: "No hledger journal was found in this topic."

config/settings.yml

@@ -10,3 +10,6 @@ hledger:
     default: 10
   hledger_max_output_bytes:
     default: 1048576
+  hledger_memory_limit_mb:
+    default: 256
+    min: 0

lib/hledger/output_limit_error.rb

@@ -0,0 +1,8 @@
+# frozen_string_literal: true
+
+module Hledger
+  # Raised when hledger produced more output than the configured cap, which
+  # means any captured JSON would be truncated.
+  class OutputLimitError < Error
+  end
+end

lib/hledger/report_builder.rb

@@ -152,8 +152,11 @@ module Hledger
 
     def run(argv, journal)
       result = @runner.execute([*base_flags, *argv], stdin_data: journal)
-      raise ExecutionError, result.stderr if result.timed_out
-      raise ExecutionError, result.stderr unless result.success?
+      raise OutputLimitError if result.output_limit_exceeded
+      raise ExecutionError, "hledger timed out: #{result.stderr}" if result.timed_out
+      unless result.success?
+        raise ExecutionError, "hledger failed (exit #{result.exit_status}): #{result.stderr}"
+      end
 
       result
     end

lib/hledger/runner.rb

@@ -10,18 +10,28 @@ module Hledger
   # a hard wall-clock timeout.
   class Runner
     Result =
-      Struct.new(:success, :stdout, :stderr, :exit_status, :timed_out, keyword_init: true) do
+      Struct.new(
+        :success,
+        :stdout,
+        :stderr,
+        :exit_status,
+        :timed_out,
+        :output_limit_exceeded,
+        keyword_init: true,
+      ) do
         def success?
           success
         end
       end
 
     READ_CHUNK = 16_384
+    MAX_FILE_SIZE = 8 * 1024 * 1024
 
-    def initialize(path: nil, timeout: nil, max_output: nil)
+    def initialize(path: nil, timeout: nil, max_output: nil, memory_limit: nil)
       @path = (path || SiteSetting.hledger_path).to_s
       @timeout = (timeout || SiteSetting.hledger_timeout_seconds).to_i
       @max_output = (max_output || SiteSetting.hledger_max_output_bytes).to_i
+      @memory_limit_mb = (memory_limit || SiteSetting.hledger_memory_limit_mb).to_i
     end
 
     def available?
@@ -46,7 +56,7 @@ module Hledger
     def run(binary, argv, stdin_data)
       tmpdir = Dir.mktmpdir("hledger-")
       env = {
-        "PATH" => ENV["PATH"].to_s,
+        "PATH" => File.dirname(binary),
         "HOME" => tmpdir,
         "TMPDIR" => tmpdir,
         "XDG_CACHE_HOME" => tmpdir,
@@ -61,12 +71,19 @@ module Hledger
         chdir: tmpdir,
         rlimit_cpu: @timeout + 5,
         rlimit_nofile: 64,
+        rlimit_fsize: MAX_FILE_SIZE,
+        rlimit_core: 0,
       }
+      # hledger is a GHC binary, so cap memory via RLIMIT_DATA (which since
+      # Linux 4.7 also covers mmap). The GHC runtime options distro packages
+      # ship with are disabled ("Most RTS options are disabled").
+      spawn_opts[:rlimit_data] = @memory_limit_mb * 1024 * 1024 if @memory_limit_mb.positive?
 
       status = nil
       timed_out = false
       stdout = +""
       stderr = +""
+      output_limit_exceeded = false
 
       Open3.popen3(env, binary, *argv, **spawn_opts) do |stdin, out, err, wait_thr|
         writer = Thread.new { write_stdin(stdin, stdin_data) }
@@ -82,8 +99,9 @@ module Hledger
         end
 
         writer.join(1)
-        stdout = out_reader.value
-        stderr = err_reader.value
+        stdout, stdout_truncated = out_reader.value
+        stderr, stderr_truncated = err_reader.value
+        output_limit_exceeded = stdout_truncated || stderr_truncated
       end
 
       Result.new(
@@ -92,6 +110,7 @@ module Hledger
         stderr: stderr,
         exit_status: status&.exitstatus,
         timed_out: timed_out,
+        output_limit_exceeded: output_limit_exceeded,
       )
     rescue SystemCallError
       failure_result
@@ -107,15 +126,23 @@ module Hledger
 
     def read_capped(io)
       buffer = +""
+      truncated = false
       while (chunk = io.read(READ_CHUNK))
         break if chunk.empty?
 
         remaining = @max_output - buffer.bytesize
-        buffer << chunk.byteslice(0, remaining) if remaining.positive?
+        if remaining <= 0
+          truncated = true
+        elsif chunk.bytesize <= remaining
+          buffer << chunk
+        else
+          buffer << chunk.byteslice(0, remaining)
+          truncated = true
+        end
       end
-      buffer
+      [buffer, truncated]
     rescue IOError, Errno::EPIPE
-      buffer
+      [buffer, truncated]
     ensure
       io.close
     end
@@ -157,7 +184,14 @@ module Hledger
     end
 
     def failure_result
-      Result.new(success: false, stdout: "", stderr: "", exit_status: nil, timed_out: false)
+      Result.new(
+        success: false,
+        stdout: "",
+        stderr: "",
+        exit_status: nil,
+        timed_out: false,
+        output_limit_exceeded: false,
+      )
     end
   end
 end

spec/lib/hledger/report_builder_spec.rb

@@ -159,4 +159,22 @@ RSpec.describe Hledger::ReportBuilder do
       described_class.new(runner: unavailable).build("accounts", journal: "x")
     }.to raise_error(Hledger::UnavailableError)
   end
+
+  it "raises when the captured output was truncated" do
+    runner = FakeHledgerRunner.new
+    allow(runner).to receive(:execute).and_return(
+      Hledger::Runner::Result.new(
+        success: true,
+        stdout: "",
+        stderr: "",
+        exit_status: 0,
+        timed_out: false,
+        output_limit_exceeded: true,
+      ),
+    )
+
+    expect { described_class.new(runner: runner).build("accounts", journal: "x") }.to raise_error(
+      Hledger::OutputLimitError,
+    )
+  end
 end

spec/lib/hledger/runner_spec.rb

@@ -1,8 +1,13 @@
 # frozen_string_literal: true
 
 RSpec.describe Hledger::Runner do
-  def runner(path:, timeout: 5, max_output: 1_000)
-    described_class.new(path: path, timeout: timeout, max_output: max_output)
+  def runner(path:, timeout: 5, max_output: 1_000, memory_limit: 0)
+    described_class.new(
+      path: path,
+      timeout: timeout,
+      max_output: max_output,
+      memory_limit: memory_limit,
+    )
   end
 
   it "captures stdout and exit status" do
@@ -25,9 +30,41 @@ RSpec.describe Hledger::Runner do
   end
 
   it "caps captured output" do
-    result = runner(path: "/bin/sh", max_output: 10).execute(["-c", "printf '%0.sa' {1..100}"])
+    result =
+      runner(path: "/bin/sh", max_output: 10).execute(["-c", "printf 'aaaaaaaaaaaaaaaaaaaa'"])
 
-    expect(result.stdout.bytesize).to be <= 10
+    expect(result.stdout.bytesize).to eq(10)
+  end
+
+  it "flags truncated output" do
+    result =
+      runner(path: "/bin/sh", max_output: 10).execute(["-c", "printf 'aaaaaaaaaaaaaaaaaaaa'"])
+
+    expect(result.output_limit_exceeded).to be(true)
+  end
+
+  it "does not flag output within the cap" do
+    result = runner(path: "/bin/echo").execute(["hello"])
+
+    expect(result.output_limit_exceeded).to be(false)
+  end
+
+  it "enforces the memory limit" do
+    result =
+      runner(path: RbConfig.ruby, memory_limit: 64).execute(
+        ["-e", "x = 'a' * (200 * 1024 * 1024); puts x.bytesize"],
+      )
+
+    expect(result).not_to be_success
+  end
+
+  it "does not limit memory when set to zero" do
+    result =
+      runner(path: RbConfig.ruby, memory_limit: 0).execute(
+        ["-e", "x = 'a' * (200 * 1024 * 1024); puts x.bytesize"],
+      )
+
+    expect(result).to be_success
   end
 
   it "returns a failure when the binary is missing" do

spec/requests/hledger/reports_spec.rb

@@ -137,6 +137,28 @@ RSpec.describe Hledger::ReportsController do
     expect(response.status).to eq(503)
   end
 
+  it "logs hledger failures without the journal" do
+    failing = StubHledgerRunner.new
+    allow(failing).to receive(:execute).and_return(
+      Hledger::Runner::Result.new(
+        success: false,
+        stdout: "",
+        stderr: "boom",
+        exit_status: 1,
+        timed_out: false,
+        output_limit_exceeded: false,
+      ),
+    )
+    allow(Hledger::Runner).to receive(:new).and_return(failing)
+    allow(Rails.logger).to receive(:warn).and_call_original
+
+    get_report("accounts")
+
+    expect(response.status).to eq(422)
+    expect(Rails.logger).to have_received(:warn).with(/hledger report failed.*boom/m)
+    expect(Rails.logger).not_to have_received(:warn).with(/equity:alice/m)
+  end
+
   it "hides topics the user cannot see" do
     private_category = Fabricate(:private_category, group: Fabricate(:group))
     hidden_post = Fabricate(:post, topic: Fabricate(:topic, category: private_category))