From ff5c5776413f368b7b226efdb6df40125c9a6ff3 Mon Sep 17 00:00:00 2001 From: connor rigby Date: Fri, 17 Feb 2017 10:03:05 -0800 Subject: [PATCH] more logging --- Makefile | 6 +- .../rootfs-additions-prod/etc/erlinit.config | 2 +- apps/farmbot/config/prod.exs | 28 ++++++++- apps/farmbot/lib/farmbot.ex | 1 + apps/farmbot/lib/logger.ex | 58 +++++++++++-------- apps/farmbot/lib/sysformatter.ex | 37 ++++++++++++ .../lib/transport/gen_mqtt/gen_mqtt.ex | 2 +- .../lib/transport/gen_mqtt/gen_mqtt_client.ex | 4 +- apps/farmbot/mix.exs | 19 ++++-- mix.lock | 4 +- 10 files changed, 123 insertions(+), 38 deletions(-) create mode 100644 apps/farmbot/lib/sysformatter.ex diff --git a/Makefile b/Makefile index 4e420af6..366ba7d9 100644 --- a/Makefile +++ b/Makefile @@ -1,7 +1,7 @@ # THIS FILE WAS GENERATED BY `build_makefile.exs` -# f1a421a -# Thu Feb 16 12:42:27 2017 -0800 -# fix-tests +# c73714b +# Thu Feb 16 13:42:21 2017 -0800 +# fix-webpack-prepare-for-release default: rpi3 diff --git a/apps/farmbot/config/hardware/rpi3/rootfs-additions-prod/etc/erlinit.config b/apps/farmbot/config/hardware/rpi3/rootfs-additions-prod/etc/erlinit.config index c9300817..626163b1 100644 --- a/apps/farmbot/config/hardware/rpi3/rootfs-additions-prod/etc/erlinit.config +++ b/apps/farmbot/config/hardware/rpi3/rootfs-additions-prod/etc/erlinit.config @@ -8,7 +8,7 @@ # GPIO UART PORT #-c ttyS0 # HDMI --c tty1 +-c ttyAMA0 # If more than one tty are available, always warn if the user is looking at # the wrong one. diff --git a/apps/farmbot/config/prod.exs b/apps/farmbot/config/prod.exs index 5cffd6f2..469acb73 100644 --- a/apps/farmbot/config/prod.exs +++ b/apps/farmbot/config/prod.exs @@ -5,5 +5,31 @@ config :farmbot, config :tzdata, :data_dir, "/tmp" config :tzdata, :autoupdate, :disabled -config :nerves_interim_wifi, regulatory_domain: "US" #FIXME + config :quantum, cron: [ "5 1 * * *": {Farmbot.Updates.Handler, :do_update_check}] + +config :nerves_interim_wifi, regulatory_domain: "US" #FIXME + +config :logger, + backends: [ + :console, + {ExSyslogger, :ex_syslogger_error}, + {ExSyslogger, :ex_syslogger_info} + ] + +config :logger, :ex_syslogger_error, + level: :error, + format: "$date $time [$level] $levelpad $metadata $message\n", + metadata: [:module, :line, :function], + ident: "Farmbot", + facility: :kern, + formatter: Farmbot.SysFormatter, + option: [:pid, :cons] + +config :logger, :ex_syslogger_info, + level: :info, + format: "$date $time [$level] $message\n", + ident: "Farmbot", + facility: :kern, + formatter: Farmbot.SysFormatter, + option: [:pid, :cons] diff --git a/apps/farmbot/lib/farmbot.ex b/apps/farmbot/lib/farmbot.ex index 97e3b9e8..964eda8a 100644 --- a/apps/farmbot/lib/farmbot.ex +++ b/apps/farmbot/lib/farmbot.ex @@ -44,6 +44,7 @@ defmodule Farmbot do @spec start(atom, [any]) :: {:ok, pid} def start(_, [args]) do Logger.debug ">> init!" + Logger.error "TEST" Amnesia.start Database.create! Keyword.put([], :memory, [node()]) Database.wait(15_000) diff --git a/apps/farmbot/lib/logger.ex b/apps/farmbot/lib/logger.ex index 9020321e..bd153db5 100644 --- a/apps/farmbot/lib/logger.ex +++ b/apps/farmbot/lib/logger.ex @@ -116,31 +116,31 @@ defmodule Farmbot.Logger do _ -> nil end end) - str = - messages - |> Enum.map(fn(m) -> "#{m.created_at}: #{m.message}\n" end) - |> List.to_string - write_to_file(str) + # str = + # messages + # |> Enum.map(fn(m) -> "#{m.created_at}: #{m.message}\n" end) + # |> List.to_string + # write_to_file(str) "/api/logs" |> HTTP.post(Poison.encode!(messages)) |> parse_resp end # Writes to a file in a transaction - @spec write_to_file(binary) :: no_return - defp write_to_file(str) do - Farmbot.System.FS.transaction fn() -> - path = Farmbot.System.FS.path <> "/log.txt" - case File.stat(path) do - # check the files size. - {:ok, %File.Stat{size: s}} when s > @max_file_size -> - File.write(path, "") - # if the file is there, we are fine. - {:ok, _stat} -> :ok - # if its not there create it. I dont think we HAVE to do this. - {:error, :enoent} -> File.write(path, "") - end - File.write(path, str, [:append]) - end - end + # @spec write_to_file(binary) :: no_return + # defp write_to_file(str) do + # Farmbot.System.FS.transaction fn() -> + # path = Farmbot.System.FS.path <> "/log.txt" + # case File.stat(path) do + # # check the files size. + # {:ok, %File.Stat{size: s}} when s > @max_file_size -> + # File.write(path, "") + # # if the file is there, we are fine. + # {:ok, _stat} -> :ok + # # if its not there create it. I dont think we HAVE to do this. + # {:error, :enoent} -> File.write(path, "") + # end + # File.write(path, str, [:append]) + # end + # end # Parses what the api sends back. Will only ever return :ok even if there was # an error. @@ -223,9 +223,19 @@ defmodule Farmbot.Logger do # Couuld probably do this inline but wheres the fun in that. its a functional # language isn't it? # Takes Loggers time stamp and converts it into a unix timestamp. - defp parse_created_at({{year, month, day}, {hour, minute, second, _}}) do - dt = Timex.to_datetime({{year, month, day}, {hour, minute, second}}) - f = DateTime.to_iso8601(dt) + defp parse_created_at({{year, month, day}, {hour, minute, second, _mil}}) do + f = %DateTime{year: year, + month: month, + day: day, + hour: hour, + minute: minute, + second: second, + microsecond: {0,0}, + std_offset: 0, + time_zone: "Etc/UTC", + utc_offset: 0, + zone_abbr: "UTC"} + |> DateTime.to_iso8601 {:ok, f} end defp parse_created_at({_,_}), do: {:ok, :os.system_time} diff --git a/apps/farmbot/lib/sysformatter.ex b/apps/farmbot/lib/sysformatter.ex new file mode 100644 index 00000000..4437177f --- /dev/null +++ b/apps/farmbot/lib/sysformatter.ex @@ -0,0 +1,37 @@ +defmodule Farmbot.SysFormatter do + @moduledoc """ + Formats sysmessages + """ + + @doc """ + Compiles a format string into an array that the `format/6` can handle. + It uses Logger.Formatter. + """ + @spec compile({atom, atom}) :: {atom, atom} + @spec compile(binary | nil) :: [Logger.Formatter.pattern | binary] + + defdelegate compile(str), to: Logger.Formatter + + @doc """ + Formats a string + """ + @spec format({atom, atom} | [Logger.Formatter.pattern | binary], + Logger.level, Logger.message, Logger.Formatter.time, + Keyword.t, list(atom)) :: IO.chardata + + def format(format, level, msg, timestamp, metadata, config_metadata) do + metadata = metadata |> Keyword.take(config_metadata) + + msg_str = format + |> Logger.Formatter.format(level, msg, timestamp, metadata) + |> try_string() + end + + defp try_string(stuff) do + try do + to_string(stuff) + rescue + _ -> inspect(stuff) + end + end +end diff --git a/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt.ex b/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt.ex index f4539518..03c1ce23 100644 --- a/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt.ex +++ b/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt.ex @@ -51,7 +51,7 @@ defmodule Farmbot.Transport.GenMqtt do # Probably a good idea to restart mqtt here. Logger.debug ">> needs to restart MQTT" if Process.alive?(client) do - GenServer.stop(client, :authorization) + GenServer.stop(client, :normal) end {:ok, pid} = start_client(new_t) {:noreply, [], {pid,new_t}} diff --git a/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt_client.ex b/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt_client.ex index cb9be098..dab017cb 100644 --- a/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt_client.ex +++ b/apps/farmbot/lib/transport/gen_mqtt/gen_mqtt_client.ex @@ -43,7 +43,6 @@ defmodule Farmbot.Transport.GenMqtt.Client do end def handle_cast({:status, %Ser{} = ser}, %Token{} = token) do - # IO.puts "!!! sending state" json = Poison.encode!(ser) GenMQTT.publish(self(), status_topic(token), json, 0, false) {:ok, token} @@ -56,14 +55,13 @@ defmodule Farmbot.Transport.GenMqtt.Client do end def handle_cast({:emit, msg}, %Token{} = token) do - # IO.puts "[!!! sending message]" json = Poison.encode! msg GenMQTT.publish(self(), frontend_topic(token), json, 0, false) {:noreply, token} end @spec terminate(any, any) :: no_return - def terminate(:authorization, _), do: :ok + def terminate(:noamrl, _), do: :ok def terminate(reason, _) do Logger.error ">>`s mqtt client died. #{inspect reason}" :ok diff --git a/apps/farmbot/mix.exs b/apps/farmbot/mix.exs index 5b6cd05a..dc3848a4 100644 --- a/apps/farmbot/mix.exs +++ b/apps/farmbot/mix.exs @@ -47,7 +47,7 @@ defmodule Farmbot.Mixfile do version: @version, commit: commit()}]}, applications: applications(), - included_applications: [:gen_mqtt, :ex_json_schema]] + included_applications: [:gen_mqtt, :ex_json_schema, :ex_syslogger]] end # common for test, prod, and dev @@ -77,17 +77,27 @@ defmodule Farmbot.Mixfile do defp deps do [ {:nerves_uart, "~> 0.1.0"}, # uart handling + {:nerves_lib, github: "nerves-project/nerves_lib"}, # this has a good uuid + {:poison, "~> 3.0"}, # json {:httpoison, github: "edgurgel/httpoison"}, - {:nerves_lib, github: "nerves-project/nerves_lib"}, # this has a good uuid + {:ex_json_schema, "~> 0.5.3"}, + {:gen_mqtt, "~> 0.3.1"}, # for rpc transport {:vmq_commons, "1.0.0", manager: :rebar3}, # This is for mqtt to work. + {:mustache, "~> 0.0.2"}, # string templating {:timex, "~> 3.0"}, # managing time. for the scheduler mostly. {:quantum, ">= 1.8.1"}, # cron jobs - {:amnesia, github: "meh/amnesia"}, # database implementation {:gen_stage, "0.11.0"}, - {:ex_json_schema, "~> 0.5.3"}, + + # Database + {:amnesia, github: "meh/amnesia"}, # database implementation + + # Log to syslog + {:ex_syslogger, "~> 1.3.3", only: :prod}, + + # Test/Dev only {:credo, "0.6.0-rc1", only: [:dev, :test]}, {:ex_doc, "~> 0.14", only: :dev}, {:dialyxir, "~> 0.4", only: [:dev], runtime: false}, @@ -98,6 +108,7 @@ defmodule Farmbot.Mixfile do {:cors_plug, "~> 1.1"}, {:cowboy, "~> 1.0.0"}, {:ex_webpack, "~> 0.1.1", runtime: false}, + # Farmbot Stuff {:"farmbot_system_#{@target}", in_umbrella: true}, {:farmbot_system, in_umbrella: true}, diff --git a/mix.lock b/mix.lock index b54e34a7..7cdd2a8b 100644 --- a/mix.lock +++ b/mix.lock @@ -13,6 +13,7 @@ "elixir_make": {:hex, :elixir_make, "0.4.0", "992f38fabe705bb45821a728f20914c554b276838433349d4f2341f7a687cddf", [:mix], []}, "ex_doc": {:hex, :ex_doc, "0.14.5", "c0433c8117e948404d93ca69411dd575ec6be39b47802e81ca8d91017a0cf83c", [:mix], [{:earmark, "~> 1.0", [hex: :earmark, optional: false]}]}, "ex_json_schema": {:hex, :ex_json_schema, "0.5.3", "f2db8eb71ca7a836607d67021d1b9c24f192dd5d1ec6b6b1c89bc934fec3bf5e", [:mix], []}, + "ex_syslogger": {:hex, :ex_syslogger, "1.3.3", "914be2c8d759d60d853790815e6cf853e4cea9e24922c01b488c172ba0b7e105", [:mix], [{:poison, ">= 1.5.0", [hex: :poison, optional: true]}, {:syslog, "~> 1.0.2", [hex: :syslog, optional: false]}]}, "ex_webpack": {:hex, :ex_webpack, "0.1.1", "d9deca1f9adfa1fa99ee2630f79756d741f17d4865bc808cd44577304fd053e3", [:mix], []}, "exjsx": {:hex, :exjsx, "3.2.1", "1bc5bf1e4fd249104178f0885030bcd75a4526f4d2a1e976f4b428d347614f0f", [:mix], [{:jsx, "~> 2.8.0", [hex: :jsx, optional: false]}]}, "exquisite": {:hex, :exquisite, "0.1.7", "4106503e976f409246731b168cd76eb54262bd04f4facc5cba82c2f53982aaf0", [:mix], []}, @@ -29,7 +30,7 @@ "mime": {:hex, :mime, "1.0.1", "05c393850524767d13a53627df71beeebb016205eb43bfbd92d14d24ec7a1b51", [:mix], []}, "mimerl": {:hex, :mimerl, "1.0.2", "993f9b0e084083405ed8252b99460c4f0563e41729ab42d9074fd5e52439be88", [:rebar3], []}, "mustache": {:hex, :mustache, "0.0.2", "870fbef411c47d17df06a57b8b3f69e26eb110cba0177c34e273db5d94369d9b", [:mix], []}, - "nerves": {:hex, :nerves, "0.4.7", "c8d08348e6f717cf140da26dc374bcf2f6f7c2bec646073aeab049e08b588173", [:mix], [{:distillery, "~> 1.0", [hex: :distillery, optional: false]}]}, + "nerves": {:git, "https://github.com/nerves-project/nerves.git", "084e3acecdc0d838671441bd75a9f4b1250bb689", [branch: "target"]}, "nerves_firmware": {:git, "https://github.com/nerves-project/nerves_firmware.git", "b783df3867c82dc0abe6770079077a6f922c00a9", []}, "nerves_firmware_http": {:git, "https://github.com/nerves-project/nerves_firmware_http.git", "aec1a9301f965e9fdd6c76d0e435c3cc48d38425", []}, "nerves_interim_wifi": {:hex, :nerves_interim_wifi, "0.1.1", "88c65ced1440e96b954189ccfc8a55cb4575cb64a8725907c3e8a9900adb2a70", [:make, :mix], [{:elixir_make, "~> 0.3", [hex: :elixir_make, optional: false]}, {:nerves_network_interface, "~> 0.3.1", [hex: :nerves_network_interface, optional: false]}, {:nerves_wpa_supplicant, "~> 0.2.2", [hex: :nerves_wpa_supplicant, optional: false]}]}, @@ -48,6 +49,7 @@ "ranch": {:hex, :ranch, "1.2.1", "a6fb992c10f2187b46ffd17ce398ddf8a54f691b81768f9ef5f461ea7e28c762", [:make], []}, "rsa": {:hex, :rsa, "0.0.1", "a63069f88ce342ffdf8448b7cdef4b39ba7dee3c1510644a39385c7e63ba246f", [:mix], []}, "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.1", "28a4d65b7f59893bc2c7de786dec1e1555bd742d336043fe644ae956c3497fbe", [:make, :rebar], []}, + "syslog": {:hex, :syslog, "1.0.2", "9cf72c0986675a170c03b210e49700845a0f7b61e96d302a3ba0df82963daf60", [:rebar], []}, "timex": {:hex, :timex, "3.1.7", "71f9c32e13ff4860e86a314303757cc02b3ead5db6e977579a2935225ce9a666", [: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]}]}, "vmq_commons": {:hex, :vmq_commons, "1.0.0", "5f5005c12db33f92f40e818a3617fb148972d59adcf99298c9d3808ef3582e34", [:rebar3], []}}