Send milliseconds in timestamp to Logstash. Reduce dependencies. Add TCP (+optional SSL)

.travis.yml

@@ -1,8 +1,6 @@
 language: elixir
 elixir:
-  - 1.3.0
   - 1.4.0
   - 1.5.0
 otp_release:
   - 18.0
-

README.md

@@ -16,6 +16,8 @@ that will send logs to the [Logstash UDP input](https://www.elastic.co/guide/en/
  be merged with the metadata sent in every log message.
  * **level**: Atom. Minimum level for this backend.
  * **type**: String.t. Type of logs. Useful to filter in logstash.
+ * **timezone**: String.t. Server timezone. Used to convert from naive timestamp. Default `"Etc/UTC"`.
+ * **json_encoder**: Atom. Module to be used for JSON encoding. Default `Jason`.
 
 ## Sample Logstash config
 ```
@@ -51,7 +53,7 @@ Add logger and tzdata as applications:
 
 ```elixir
 def application do
-  [applications: [:logger, :timex]]
+  [applications: [:logger]]
 end
 ```
 
@@ -81,5 +83,7 @@ config :logger, :error_log,
   type: "my_type_of_app_or_node",
   metadata: [
     extra_fields: "go here"
-  ]
+  ],
+  timezone: "Etc/UTC",
+  json_encoder: Jason
 ```

lib/logger_logstash_backend.ex

@@ -15,7 +15,6 @@
 ################################################################################
 defmodule LoggerLogstashBackend do
   @behaviour :gen_event
-  use Timex
 
   def init({__MODULE__, name}) do
     {:ok, configure(name, [])}
@@ -34,11 +33,13 @@ defmodule LoggerLogstashBackend do
   end
 
   def handle_event(
-    {level, _gl, {Logger, msg, ts, md}}, %{level: min_level} = state
-  ) do
+        {level, _gl, {Logger, msg, ts, md}},
+        %{level: min_level} = state
+      ) do
     if is_nil(min_level) or Logger.compare_levels(level, min_level) != :lt do
-      log_event level, msg, ts, md, state
+      log_event(level, msg, ts, md, state)
     end
+
     {:ok, state}
   end
 
@@ -50,54 +51,72 @@ defmodule LoggerLogstashBackend do
     :ok
   end
 
-  defp log_event(
-    level, msg, ts, md, %{
-      host: host,
-      port: port,
-      type: type,
-      metadata: metadata,
-      socket: socket
-    }
-  ) do
-    fields = md
-             |> Keyword.merge(metadata)
-             |> Enum.into(%{})
-             |> Map.put(:level, to_string(level))
-             |> inspect_pids
-
-    {{year, month, day}, {hour, minute, second, milliseconds}} = ts
-    {:ok, ts} = NaiveDateTime.new(
-      year, month, day, hour, minute, second, (milliseconds * 1000)
-    )
-    ts = Timex.to_datetime ts, Timezone.local
-    {:ok, json} = JSX.encode %{
-      type: type,
-      "@timestamp": Timex.format!(ts, "{ISO:Extended}"),
-      message: to_string(msg),
-      fields: fields
-    }
-    :gen_udp.send socket, host, port, to_charlist(json)
+  defp log_event(level, msg, ts, md, %{
+         host: host,
+         port: port,
+         type: type,
+         metadata: metadata,
+         socket: socket,
+         timezone: timezone,
+         json_encoder: json_encoder
+       }) do
+    fields =
+      md
+      |> Keyword.merge(metadata)
+      |> Enum.into(%{})
+      |> Map.put(:level, to_string(level))
+      |> inspect_pids
+
+    {{year, month, day}, {hour, minute, second, microseconds}} = ts
+
+    {:ok, ts} =
+      NaiveDateTime.new(
+        year,
+        month,
+        day,
+        hour,
+        minute,
+        second,
+        microseconds * 1000
+      )
+
+    {:ok, datetime} = DateTime.from_naive(ts, timezone)
+
+    {:ok, json} =
+      json_encoder.encode(%{
+        type: type,
+        "@timestamp": DateTime.to_iso8601(datetime),
+        message: to_string(msg),
+        fields: fields
+      })
+
+    :gen_udp.send(socket, host, port, to_charlist(json))
   end
 
   defp configure(name, opts) do
-    env = Application.get_env :logger, name, []
-    opts = Keyword.merge env, opts
-    Application.put_env :logger, name, opts
-
-    level = Keyword.get opts, :level, :debug
-    metadata = Keyword.get opts, :metadata, []
-    type = Keyword.get opts, :type, "elixir"
-    host = Keyword.get opts, :host
-    port = Keyword.get opts, :port
-    {:ok, socket} = :gen_udp.open 0
+    env = Application.get_env(:logger, name, [])
+    opts = Keyword.merge(env, opts)
+    Application.put_env(:logger, name, opts)
+
+    level = Keyword.get(opts, :level, :debug)
+    metadata = Keyword.get(opts, :metadata, [])
+    type = Keyword.get(opts, :type, "elixir")
+    host = Keyword.get(opts, :host)
+    port = Keyword.get(opts, :port)
+    timezone = Keyword.get(opts, :timezone, "Etc/UTC")
+    json_encoder = Keyword.get(opts, :json_encoder, Jason)
+    {:ok, socket} = :gen_udp.open(0)
+
     %{
       name: name,
       host: to_charlist(host),
       port: port,
       level: level,
       socket: socket,
       type: type,
-      metadata: metadata
+      metadata: metadata,
+      timezone: timezone,
+      json_encoder: json_encoder
     }
   end
 
@@ -107,8 +126,8 @@ defmodule LoggerLogstashBackend do
 
   # inspects the field values only if they are pids
   defp inspect_pids(fields) when is_map(fields) do
-    Enum.into fields, %{}, fn {key, value} ->
+    Enum.into(fields, %{}, fn {key, value} ->
       {key, inspect_pid(value)}
-    end
+    end)
   end
 end

mix.exs

@@ -2,26 +2,27 @@ defmodule LoggerLogstashBackend.Mixfile do
   use Mix.Project
 
   def project do
-    [app: :logger_logstash_backend,
-     name: "logger_logstash_backend",
-     source_url: "https://github.com/marcelog/logger_logstash_backend",
-     version: "5.0.0",
-     elixir: "~> 1.3",
-     description: description(),
-     package: package(),
-     deps: deps()]
+    [
+      app: :logger_logstash_backend,
+      name: "logger_logstash_backend",
+      source_url: "https://github.com/marcelog/logger_logstash_backend",
+      version: "5.0.0",
+      elixir: "~> 1.4",
+      description: description(),
+      package: package(),
+      deps: deps()
+    ]
   end
 
   def application do
-    [applications: [:logger, :timex, :exjsx]]
+    [applications: [:logger]]
   end
 
   defp deps do
     [
       {:earmark, "~> 1.0.3", only: :dev},
       {:ex_doc, "~> 0.14.5", only: :dev},
-      {:exjsx, "~> 3.2.1"},
-      {:timex, "~> 3.1.8"}
+      {:jason, "~> 1.0", only: [:dev, :test]}
     ]
   end
 

mix.lock

@@ -1,14 +1,17 @@
-%{"certifi": {:hex, :certifi, "0.7.0", "861a57f3808f7eb0c2d1802afeaae0fa5de813b0df0979153cbafcd853ababaf", [:rebar3], []},
+%{
+  "certifi": {:hex, :certifi, "0.7.0", "861a57f3808f7eb0c2d1802afeaae0fa5de813b0df0979153cbafcd853ababaf", [:rebar3], []},
   "combine": {:hex, :combine, "0.9.6", "8d1034a127d4cbf6924c8a5010d3534d958085575fa4d9b878f200d79ac78335", [:mix], []},
   "earmark": {:hex, :earmark, "1.0.3", "89bdbaf2aca8bbb5c97d8b3b55c5dd0cff517ecc78d417e87f1d0982e514557b", [:mix], []},
   "ex_doc": {:hex, :ex_doc, "0.14.5", "c0433c8117e948404d93ca69411dd575ec6be39b47802e81ca8d91017a0cf83c", [:mix], [{:earmark, "~> 1.0", [hex: :earmark, optional: false]}]},
   "exjsx": {:hex, :exjsx, "3.2.1", "1bc5bf1e4fd249104178f0885030bcd75a4526f4d2a1e976f4b428d347614f0f", [:mix], [{:jsx, "~> 2.8.0", [hex: :jsx, optional: false]}]},
   "gettext": {:hex, :gettext, "0.13.0", "daafbddc5cda12738bb93b01d84105fe75b916a302f1c50ab9fb066b95ec9db4", [:mix], []},
   "hackney": {:hex, :hackney, "1.6.5", "8c025ee397ac94a184b0743c73b33b96465e85f90a02e210e86df6cbafaa5065", [:rebar3], [{:certifi, "0.7.0", [hex: :certifi, optional: false]}, {:idna, "1.2.0", [hex: :idna, optional: false]}, {:metrics, "1.0.1", [hex: :metrics, optional: false]}, {:mimerl, "1.0.2", [hex: :mimerl, optional: false]}, {:ssl_verify_fun, "1.1.1", [hex: :ssl_verify_fun, optional: false]}]},
   "idna": {:hex, :idna, "1.2.0", "ac62ee99da068f43c50dc69acf700e03a62a348360126260e87f2b54eced86b2", [:rebar3], []},
+  "jason": {:hex, :jason, "1.0.0", "0f7cfa9bdb23fed721ec05419bcee2b2c21a77e926bce0deda029b5adc716fe2", [:mix], [{:decimal, "~> 1.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm"},
   "jsx": {:hex, :jsx, "2.8.1", "1453b4eb3615acb3e2cd0a105d27e6761e2ed2e501ac0b390f5bbec497669846", [:mix, :rebar3], []},
   "metrics": {:hex, :metrics, "1.0.1", "25f094dea2cda98213cecc3aeff09e940299d950904393b2a29d191c346a8486", [:rebar3], []},
   "mimerl": {:hex, :mimerl, "1.0.2", "993f9b0e084083405ed8252b99460c4f0563e41729ab42d9074fd5e52439be88", [:rebar3], []},
   "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.1", "28a4d65b7f59893bc2c7de786dec1e1555bd742d336043fe644ae956c3497fbe", [:make, :rebar], []},
   "timex": {:hex, :timex, "3.1.8", "a32f636c4260dd7515a3767be3d3a163dc09d15f0e9e689254b7bab152b29209", [:mix], [{:combine, "~> 0.7", [hex: :combine, optional: false]}, {:gettext, "~> 0.10", [hex: :gettext, optional: false]}, {:tzdata, "~> 0.1.8 or ~> 0.5", [hex: :tzdata, optional: false]}]},
-  "tzdata": {:hex, :tzdata, "0.5.10", "087e8dfe8c0283473115ad8ca6974b898ecb55ca5c725427a142a79593391e90", [:mix], [{:hackney, "~> 1.0", [hex: :hackney, optional: false]}]}}
+  "tzdata": {:hex, :tzdata, "0.5.10", "087e8dfe8c0283473115ad8ca6974b898ecb55ca5c725427a142a79593391e90", [:mix], [{:hackney, "~> 1.0", [hex: :hackney, optional: false]}]},
+}

test/logger_logstash_backend_test.exs

@@ -16,83 +16,93 @@
 defmodule LoggerLogstashBackendTest do
   use ExUnit.Case, async: false
   require Logger
-  use Timex
 
   @backend {LoggerLogstashBackend, :test}
-  Logger.add_backend @backend
+  Logger.add_backend(@backend)
 
   setup do
-    Logger.configure_backend @backend, [
+    Logger.configure_backend(
+      @backend,
       host: "127.0.0.1",
       port: 10001,
       level: :info,
       type: "some_app",
       metadata: [
         some_metadata: "go here"
       ]
-    ]
-    {:ok, socket} = :gen_udp.open 10001, [:binary, {:active, true}]
-    on_exit fn ->
-      :ok = :gen_udp.close socket
-    end
+    )
+
+    {:ok, socket} = :gen_udp.open(10001, [:binary, {:active, true}])
+
+    on_exit(fn ->
+      :ok = :gen_udp.close(socket)
+    end)
+
     :ok
   end
 
   test "can log" do
-    Logger.info "hello world", [key1: "field1"]
+    Logger.info("hello world", key1: "field1")
     json = get_log()
-    {:ok, data} = JSX.decode json
+    {:ok, data} = Jason.decode(json)
     assert data["type"] === "some_app"
     assert data["message"] === "hello world"
+
     expected = %{
       "function" => "test can log/1",
       "level" => "info",
       "module" => "Elixir.LoggerLogstashBackendTest",
-      "pid" => (inspect self()),
+      "pid" => inspect(self()),
       "some_metadata" => "go here",
-      "line" => 42,
+      "line" => 45,
       "key1" => "field1"
     }
+
+    assert data["fields"]["line"] == expected["line"]
     assert contains?(data["fields"], expected)
-    {:ok, ts} = Timex.parse data["@timestamp"], "{ISO:Extended}"
-    ts = Timex.to_unix ts
+    {:ok, dt, _tz_offset} = DateTime.from_iso8601(data["@timestamp"])
+    ts = DateTime.to_unix(dt)
 
-    now = Timex.to_unix Timex.local
-    assert (now - ts) < 1000
+    now = DateTime.utc_now() |> DateTime.to_unix()
+    assert now - ts < 1000
   end
 
   test "can log pids" do
-    Logger.info "pid", [pid_key: self()]
+    Logger.info("pid", pid_key: self())
     json = get_log()
-    {:ok, data} = JSX.decode json
+    {:ok, data} = Jason.decode(json)
     assert data["type"] === "some_app"
     assert data["message"] === "pid"
+
     expected = %{
       "function" => "test can log pids/1",
       "level" => "info",
       "module" => "Elixir.LoggerLogstashBackendTest",
-      "pid" => (inspect self()),
+      "pid" => inspect(self()),
       "pid_key" => inspect(self()),
       "some_metadata" => "go here",
-      "line" => 65
+      "line" => 71
     }
+
+    assert data["fields"]["line"] == expected["line"]
     assert contains?(data["fields"], expected)
-    {:ok, ts} = Timex.parse data["@timestamp"], "{ISO:Extended}"
-    ts = Timex.to_unix ts
+    {:ok, dt, _tz_offset} = DateTime.from_iso8601(data["@timestamp"])
+    ts = DateTime.to_unix(dt)
 
-    now = Timex.to_unix Timex.local
-    assert (now - ts) < 1000
+    now = DateTime.utc_now() |> DateTime.to_unix()
+    assert now - ts < 1000
   end
 
   test "cant log when minor levels" do
-    Logger.debug "hello world", [key1: "field1"]
+    Logger.debug("hello world", key1: "field1")
     :nothing_received = get_log()
   end
 
   defp get_log do
     receive do
       {:udp, _, _, _, json} -> json
-    after 500 -> :nothing_received
+    after
+      500 -> :nothing_received
     end
   end