Support Devices sending log messages via a new Logging extension (#2080)

Companion to nerves-hub/nerves_hub_link#303

New log lines are streamed to the UI, with only 25 max shown.

This has been implemented using
**[ClickHouse](https://clickhouse.com/)**.

I've also used [hammer](https://hexdocs.pm/hammer) for rate limiting log
messages (3 per second, with a burst capacity of 10).

**Pros:**
- built-in row truncation (defaults to 3 days)
- isolate analytics from core platform functionality
- the analytics system isn't required, and if turned off, the logging
extension can't be attached

**Cons:**
- we don't get transaction isolation in tests
- we don't get nice association helpers as these are separate ecto repos

**Future possibilities:**
- "Show more"
- Filtering on level 
- Graph of number of log lines over X period
- Search log messages (not sure how well this would work with
ClickHouse)

**Things to note:**
- using `make iex-server` will try to start the analytics subsystem
- to skip the analytics subsystem, use `ANALYTICS_ENABLED=false make
iex-server`
- the docker compose file has been updated to include ClickHouse, its
recommended to use this for starting supplementary systems like Postgres
and ClickHouse.

---

**Simple UI** (to start with)


https://github.com/user-attachments/assets/b4ccd5e8-2411-4423-809e-8b48d19ebbff

---

**To finish:**

- [x] `device_log_lines` truncation (customizable time period)
- [x] tests

---------

Co-authored-by: Nate Shoemaker <[email protected]>

Author: joshk

.cspell.json

@@ -22,6 +22,7 @@
     "castore",
     "checkmark",
     "circuitboard",
+    "clickhouse",
     "clipcopy",
     "comeonin",
     "conzole",

.dialyzer_ignore.exs

@@ -2,5 +2,6 @@
   {"lib/x509/certificate.ex", "Unknown type: X509.ASN1.record/1."},
   {"lib/x509/certificate/extension.ex", "Unknown type: X509.ASN1.record/1."},
   {"lib/nerves_hub_web/channels/device_channel.ex", :unmatched_return, 1},
-  {"lib/nerves_hub_web/channels/device_socket.ex", :unmatched_return, 1}
+  {"lib/nerves_hub_web/channels/device_socket.ex", :unmatched_return, 1},
+  {"lib/nerves_hub/analytics_repo.ex", :contract_supertype, 1}
 ]

.github/workflows/ci.yml

@@ -22,6 +22,7 @@ jobs:
       FWUP_VERSION: "1.12.0"
       MIX_ENV: "test"
       DATABASE_URL: postgres://postgres:postgres@localhost:5432/nerves_hub_test
+      CLICKHOUSE_URL: http://default:@localhost:8123/default
 
     services:
       db:
@@ -34,6 +35,13 @@ jobs:
           --health-interval 10s
           --health-timeout 5s
           --health-retries 5
+      clickhouse:
+        image: clickhouse/clickhouse-server:25.4.2.31
+        env:
+          CLICKHOUSE_SKIP_USER_SETUP: 1
+        ports:
+          - "8123:8123"
+          - "9000:9000"
 
     steps:
       - name: Install system deps
@@ -47,7 +55,7 @@ jobs:
       - name: Set up Node.js
         uses: actions/setup-node@v4
         with:
-          node-version: '20'
+          node-version: "20"
 
       - name: Install cspell
         run: npm install -g cspell

assets/ui-rework/app.js

@@ -14,6 +14,7 @@ import DeviceLocationMapWithGeocoder from "./hooks/deviceLocationMapWithGeocoder
 import Flash from "./hooks/flash.js"
 import HighlightCode from "./hooks/highlightCode.js"
 import LocalTime from "./hooks/localTime.js"
+import LogLineLocalTime from "./hooks/logLineLocalTime.js"
 import SharedSecretClipboardClick from "./hooks/sharedSecretClipboardClick.js"
 import SimpleDate from "./hooks/simpleDate.js"
 import SupportScriptOutput from "./hooks/supportScriptOutput.js"
@@ -38,6 +39,7 @@ let liveSocket = new LiveSocket("/live", Socket, {
     Flash,
     HighlightCode,
     LocalTime,
+    LogLineLocalTime,
     SharedSecretClipboardClick,
     SimpleDate,
     SupportScriptOutput,

assets/ui-rework/hooks/logLineLocalTime.js

@@ -0,0 +1,62 @@
+export default {
+  mounted() {
+    this.updated()
+  },
+  updated() {
+    let dt = new Date(this.el.textContent.trim())
+
+    function p(s) {
+      return s < 10 ? "0" + s : s
+    }
+
+    function p3(s) {
+      let result
+      if (s < 10) {
+        result = "00" + s
+      } else if (s < 100) {
+        result = "0" + s
+      } else {
+        result = s
+      }
+      return result
+    }
+
+    const tzAbbr = () => {
+      var dateObject = new Date(),
+        dateString = dateObject + "",
+        tzAbbr =
+          // Works for the majority of modern browsers
+          dateString.match(/\(([^\)]+)\)$/) ||
+          // IE outputs date strings in a different format:
+          dateString.match(/([A-Z]+) [\d]{4}$/)
+
+      if (tzAbbr) {
+        // Old Firefox uses the long timezone name (e.g., "Central
+        // Daylight Time" instead of "CDT")
+        tzAbbr = tzAbbr[1].match(/[A-Z]/g).join("")
+      }
+
+      // Return a GMT offset for browsers that don't include the
+      // user's zone abbreviation (e.g. "GMT-0500".)
+      // First seen on: http://stackoverflow.com/a/12496442
+      if (!tzAbbr && /(GMT\W*\d{4})/.test(dateString)) {
+        return /(GMT\W*\d{4})/.exec(dateString)[1]
+      }
+
+      return tzAbbr
+    }
+
+    const day = dt.getDate()
+    const month = dt.getMonth() + 1
+    const year = dt.getFullYear()
+    const hour = dt.getHours()
+    const minute = dt.getMinutes()
+    const seconds = dt.getSeconds()
+    const milliseconds = dt.getMilliseconds()
+    const timezone = tzAbbr()
+
+    const time = `${p(hour)}:${p(minute)}:${p(seconds)}.${p3(milliseconds)}`
+
+    this.el.textContent = `${year}-${p(month)}-${p(day)} ${time} ${timezone}`
+  }
+}

config/config.exs

@@ -18,7 +18,7 @@ config :mime, :types, %{
 config :nerves_hub,
   env: Mix.env(),
   namespace: NervesHub,
-  ecto_repos: [NervesHub.Repo]
+  ecto_repos: [NervesHub.AnalyticsRepo, NervesHub.Repo]
 
 ##
 # NervesHub Device

config/dev.exs

@@ -88,6 +88,15 @@ config :nerves_hub, NervesHub.ObanRepo,
   pool_size: 10,
   ssl: false
 
+if System.get_env("ANALYTICS_ENABLED", "true") == "true" do
+  config :nerves_hub, NervesHub.AnalyticsRepo,
+    url: System.get_env("CLICKHOUSE_URL", "http://default:@localhost:8123/default")
+
+  config :nerves_hub, analytics_enabled: true
+else
+  config :nerves_hub, analytics_enabled: false
+end
+
 ##
 # Firmware upload
 #

config/runtime.exs

@@ -50,6 +50,9 @@ config :nerves_hub,
         System.get_env("FEATURES_HEALTH_INTERVAL_MINUTES", "60") |> String.to_integer(),
       ui_polling_seconds:
         System.get_env("FEATURES_HEALTH_UI_POLLING_SECONDS", "60") |> String.to_integer()
+    ],
+    logging: [
+      days_to_keep: String.to_integer(System.get_env("EXTENSIONS_LOGGING_DAYS_TO_KEEP", "3"))
     ]
   ],
   new_ui: System.get_env("NEW_UI_ENABLED", "true") == "true"
@@ -264,6 +267,16 @@ if config_env() == :prod do
     database_auto_migrator: System.get_env("DATABASE_AUTO_MIGRATOR", "true") == "true"
 end
 
+if config_env() == :prod do
+  if clickhouse_url = System.get_env("CLICKHOUSE_URL") do
+    config :nerves_hub, NervesHub.AnalyticsRepo, url: clickhouse_url
+
+    config :nerves_hub, analytics_enabled: true
+  else
+    config :nerves_hub, analytics_enabled: false
+  end
+end
+
 # Libcluster is using Postgres for Node discovery
 # The library only accepts keyword configs, so the DATABASE_URL has to be
 # parsed and put together with the ssl pieces from above.

config/test.exs

@@ -71,6 +71,11 @@ config :nerves_hub, NervesHub.ObanRepo,
   pool: Ecto.Adapters.SQL.Sandbox,
   pool_size: 10
 
+config :nerves_hub, NervesHub.AnalyticsRepo,
+  url: System.get_env("CLICKHOUSE_URL", "http://default:@localhost:8123/default")
+
+config :nerves_hub, analytics_enabled: true
+
 config :nerves_hub, Oban, testing: :manual
 
 ##

docker-compose.yml

@@ -1,5 +1,3 @@
-version: "3.9"
-
 services:
   postgres:
     image: postgres:16
@@ -8,3 +6,15 @@ services:
       POSTGRES_PASSWORD: postgres
     ports:
       - 5432:5432
+  clickhouse:
+    image: clickhouse/clickhouse-server:25.4.2.31
+    container_name: clickhouse-server
+    environment:
+      CLICKHOUSE_SKIP_USER_SETUP: 1
+    ports:
+      - "8123:8123"
+      - "9000:9000"
+    ulimits:
+      nofile:
+        soft: 262144
+        hard: 262144