Server to client error messages (#1406)

https://linear.app/electric-sql/issue/VAX-1983/improve-error-reporting-from-server-to-client

This PR add the ability of the client to show friendly error messages
when the error has originated on the server.

For example:

```
an error occurred in satellite: INVALID_REQUEST Unexpected value for int2 column: 32769
```

At this stage I've not tried to hide any noise such as the stack trace
in these scenarios. So the user in fact sees all of this:
```
an error occurred in satellite: INVALID_REQUEST Unexpected value for int2 column: 32769
Client can't connect with the server after a fatal error. This can happen due to divergence between local client and server. Use developer tools to clear the local database, or delete the database file. We're working on tools to allow recovering the state of the local database.
/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/error.js:35
  return new SatelliteError(
         ^


SatelliteError: Fatal error: Unexpected value for int2 column: 32769. Check log for more information
    at wrapFatalError (/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/error.js:35:10)
    at SatelliteProcess._handleOrThrowClientError (/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/process.js:542:13)
    at SatelliteProcess._handleClientError (/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/process.js:525:10)
    at <anonymous> (/Users/rob/src/electric-sql/electric/clients/typescript/dist/util/asyncEventEmitter.js:103:17)
    at Array.map (<anonymous>)
    at AsyncEventEmitter.processQueue (/Users/rob/src/electric-sql/electric/clients/typescript/dist/util/asyncEventEmitter.js:101:32)
    at AsyncEventEmitter.enqueueEmit (/Users/rob/src/electric-sql/electric/clients/typescript/dist/util/asyncEventEmitter.js:129:12)
    at SatelliteClient.handleError (/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/client.js:725:18)
    at Object.SatErrorResp (/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/client.js:98:37)
    at SatelliteClient.handleIncoming (/Users/rob/src/electric-sql/electric/clients/typescript/dist/satellite/client.js:801:47) {
  code: 12
}
```

I've also added friendly error message generation on the server for data
validation errors as an example of how you would implement the friendly
error messages. Once the permissions system has been added, rejected
writes could also generate a friendly error message in a similar way.

The client will now also see error messages that were already being set
in the SatErrorResp such as:
- Postgres is unavailable
- Acknowledged unknown txn
- Connection to central database failed, cannot continue the replication
because of possible consistency issues

---------

Co-authored-by: Oleksii Sholik <[email protected]>

clients/typescript/src/satellite/process.ts

@@ -807,7 +807,11 @@ export class SatelliteProcess implements Satellite {
       throw satelliteError
     }
 
-    Log.warn(`an error occurred in satellite: ${satelliteError.message}`)
+    Log.warn(
+      `an error occurred in satellite: ${
+        SatelliteErrorCode[satelliteError.code]
+      } ${satelliteError.message}`
+    )
 
     this._handleOrThrowClientError(satelliteError)
   }

clients/typescript/src/util/proto.ts

@@ -244,7 +244,7 @@ export function serverErrorToSatelliteError(
 ): SatelliteError {
   return new SatelliteError(
     serverErrorToSatError[error.errorType],
-    'server error'
+    'Server error: ' + error.message
   )
 }
 

components/electric/lib/electric/satellite/protocol.ex

@@ -18,6 +18,7 @@ defmodule Electric.Satellite.Protocol do
   alias Electric.Replication.Shapes
   alias Electric.Replication.Shapes.ShapeRequest
   alias Electric.Satellite.Serialization
+  alias Electric.Satellite.Serialization.DataValidationError
   alias Electric.Satellite.ClientManager
   alias Electric.Satellite.WriteValidation
   alias Electric.Satellite.ClientReconnectionInfo
@@ -485,7 +486,7 @@ defmodule Electric.Satellite.Protocol do
         Telemetry.event(state, :bad_transaction)
 
         Logger.error(Exception.format(:error, e, __STACKTRACE__))
-        {:error, %SatErrorResp{error_type: :INVALID_REQUEST}}
+        {:error, %SatErrorResp{error_type: :INVALID_REQUEST, message: friendly_error_message(e)}}
     end
   end
 
@@ -1350,4 +1351,7 @@ defmodule Electric.Satellite.Protocol do
     do: Electric.Postgres.Dialect.SQLite
 
   defp decode_sql_dialect(:POSTGRES), do: Electric.Postgres.Dialect.Postgresql
+
+  defp friendly_error_message(%DataValidationError{} = error), do: Exception.message(error)
+  defp friendly_error_message(_), do: "unexpected error"
 end

components/electric/lib/electric/satellite/serialization.ex

@@ -1,6 +1,7 @@
 defmodule Electric.Satellite.Serialization do
   alias Electric.Satellite.Protocol
   alias Electric.Satellite.SatOpGone
+  alias Electric.Satellite.Serialization.DataValidationError
   alias Electric.Replication.Changes.Gone
   alias Electric.Postgres.Extension.SchemaCache
   alias Electric.Postgres.{Extension, Replication}
@@ -559,7 +560,7 @@ defmodule Electric.Satellite.Serialization do
   def decode_column_value!(val, :bool) when val in ["t", "f"], do: val
 
   def decode_column_value!(val, :bool) do
-    raise "Unexpected value for bool column: #{inspect(val)}"
+    raise DataValidationError, message: "Unexpected value for bool column: #{inspect(val)}"
   end
 
   def decode_column_value!(val, type) when type in [:text, :varchar] do
@@ -589,6 +590,11 @@ defmodule Electric.Satellite.Serialization do
     _ = Date.from_iso8601!(val)
 
     val
+  rescue
+    _ ->
+      reraise DataValidationError,
+              [message: "Unexpected value for :date column: #{inspect(val)}"],
+              __STACKTRACE__
   end
 
   def decode_column_value!(val, type) when type in [:float4, :float8] do
@@ -599,16 +605,25 @@ defmodule Electric.Satellite.Serialization do
   end
 
   def decode_column_value!(val, type) when type in [:int2, :int4, :int8] do
-    val
-    |> String.to_integer()
-    |> assert_valid_integer!(type)
+    case Integer.parse(val) do
+      {int, ""} ->
+        assert_valid_integer!(int, type)
+        val
 
-    val
+      _ ->
+        raise DataValidationError, message: "Non-integer value given for #{type} column: #{val}"
+    end
   end
 
   def decode_column_value!(val, type) when type in [:json, :jsonb] do
-    _ = Jason.decode!(val)
-    val
+    case Jason.decode(val) do
+      {:ok, _} ->
+        val
+
+      {:error, %Jason.DecodeError{} = error} ->
+        raise DataValidationError,
+          message: "Invalid JSON found in #{type} column: #{Exception.message(error)}"
+    end
   end
 
   def decode_column_value!(val, :time) do
@@ -628,36 +643,71 @@ defmodule Electric.Satellite.Serialization do
     _ = Time.from_iso8601!(val)
 
     val
+  rescue
+    _ ->
+      reraise DataValidationError,
+              [message: "Unexpected value for :time column: #{inspect(val)}"],
+              __STACKTRACE__
   end
 
   def decode_column_value!(val, :timestamp) do
-    # NaiveDateTime silently discards time zone offset if it is present in the string. But we want to reject such strings
-    # because values of type `timestamp` must not have an offset.
-    {:error, :missing_offset} = DateTime.from_iso8601(val)
+    case DateTime.from_iso8601(val) do
+      {:ok, _, _} ->
+        # NaiveDateTime silently discards time zone offset if it is present in the string. But we want to reject such strings
+        # because values of type `timestamp` must not have an offset.
+        raise DataValidationError,
+          message: "Unexpected offset provided for timestamp column: #{inspect(val)}"
 
-    dt = NaiveDateTime.from_iso8601!(val)
-    assert_valid_year!(dt.year)
+      {:error, :missing_offset} ->
+        dt = NaiveDateTime.from_iso8601!(val)
+        assert_valid_year!(dt.year)
 
-    val
+        val
+
+      {:error, :invalid_format} ->
+        raise DataValidationError,
+          message: "Unexpected format provided for timestamp column: #{inspect(val)}"
+    end
   end
 
   def decode_column_value!(val, :timestamptz) do
     # The offset of datetimes coming over the Satellite protocol MUST be 0.
-    {:ok, dt, 0} = DateTime.from_iso8601(val)
-    assert_valid_year!(dt.year)
+    case DateTime.from_iso8601(val) do
+      {:ok, dt, 0} ->
+        assert_valid_year!(dt.year)
 
-    val
+        val
+
+      {:ok, _, _} ->
+        raise DataValidationError,
+          message: "Non-zeo offset provided for timestamptz column: #{inspect(val)}"
+
+      {:error, :invalid_format} ->
+        raise DataValidationError,
+          message: "Unexpected format for timestamptz column: #{inspect(val)}"
+
+      {:error, :missing_offset} ->
+        raise DataValidationError,
+          message: "Missing offset in timestamptz column: #{inspect(val)}"
+    end
   end
 
   def decode_column_value!(val, :uuid) do
-    Electric.Utils.validate_uuid!(val)
+    case Electric.Utils.validate_uuid(val) do
+      {:ok, uuid} ->
+        uuid
+
+      :error ->
+        raise DataValidationError, message: "Unexpected value for uuid column: #{inspect(val)}"
+    end
   end
 
   def decode_column_value!(val, {:enum, typename, values}) do
     if val in values do
       val
     else
-      raise "Unexpected value #{inspect(val)} for enum type #{typename}"
+      raise DataValidationError,
+        message: "Unexpected value #{inspect(val)} for enum type #{typename}"
     end
   end
 
@@ -668,7 +718,7 @@ defmodule Electric.Satellite.Serialization do
         val
 
       _ ->
-        raise "Unexpected value for #{type} colum: #{inspect(val)}"
+        raise DataValidationError, message: "Unexpected value for #{type} column: #{inspect(val)}"
     end
   end
 
@@ -680,6 +730,9 @@ defmodule Electric.Satellite.Serialization do
   defp assert_valid_integer!(int, :int4) when int in @int4_range, do: :ok
   defp assert_valid_integer!(int, :int8) when int in @int8_range, do: :ok
 
+  defp assert_valid_integer!(int, type),
+    do: raise(DataValidationError, message: "Value out of range for #{type} column: #{int}")
+
   # Postgres[1] uses BC/AD suffixes to indicate whether the date is in the Common Era or precedes it. Postgres assumes year
   # 0 did not exist, so in its worldview '0001-12-31 BC' is immediately followed by '0001-01-01'.
   #
@@ -694,6 +747,9 @@ defmodule Electric.Satellite.Serialization do
   #   [2]: https://www.sqlite.org/lang_datefunc.html
   defp assert_valid_year!(year) when year in 1..9999, do: :ok
 
+  defp assert_valid_year!(year),
+    do: raise(DataValidationError, message: "Year out of range: #{year}")
+
   defp assert_valid_month!(month) when month in 1..12, do: :ok
 
   defp assert_valid_day!(day) when day in 1..31, do: :ok
@@ -731,7 +787,7 @@ defmodule Electric.Satellite.Serialization do
       end
 
     with :error <- conversion_result do
-      raise "Value for float4 column out of range: #{inspect(num)}"
+      raise DataValidationError, message: "Value for float4 column out of range: #{inspect(num)}"
     end
   end
 end

components/electric/lib/electric/satellite/serialization/data_validation_error.ex

@@ -0,0 +1,3 @@
+defmodule Electric.Satellite.Serialization.DataValidationError do
+  defexception [:message]
+end

components/electric/test/electric/satellite/serialization_test.exs

@@ -8,6 +8,7 @@ defmodule Electric.Satellite.SerializationTest do
   alias Electric.Postgres.{Lsn, Schema, Extension.SchemaCache}
   alias Electric.Replication.Changes.Transaction
   alias Electric.Satellite.Serialization
+  alias Electric.Satellite.Serialization.DataValidationError
   alias Electric.Postgres.MockSchemaLoader
 
   describe "map_to_row" do
@@ -262,7 +263,7 @@ defmodule Electric.Satellite.SerializationTest do
         try do
           Serialization.decode_record!(row, columns)
         rescue
-          _ -> :ok
+          DataValidationError -> :ok
         else
           val -> flunk("Expected decode_record!() to raise but it returned #{inspect(val)}")
         end