plausible / community-edition

Example Docker Compose setup for hosting Plausible Community Edition
1.28k stars 286 forks source link

[error] <PID> running PlausibleWeb.Endpoint (connection stream id ) terminated | (Protocol.UndefinedError) protocol Jason.Encoder not implemented for #125

Closed wreidlinger closed 1 month ago

wreidlinger commented 4 months ago

Hi there,

we run the plausible community edition via docker compose. Looks like not all visitors get tracked correctly. We saw the following logs, is this normal or can somebody tell me if there is a problem with the config?!

sudo docker compose logs -ft
plausible_plausible  | 2024-05-22T19:51:21.286465807Z 19:51:21.284 [error] #PID<0.4511.0> running PlausibleWeb.Endpoint (connection #PID<0.4288.0>, stream id 43) terminated
plausible_plausible  | 2024-05-22T19:51:21.286542968Z Server: plausible.mydomain.com:80 (http)
plausible_plausible  | 2024-05-22T19:51:21.286551008Z Request: GET /api/plugins/v1/capabilities
plausible_plausible  | 2024-05-22T19:51:21.286555488Z ** (exit) an exception was raised:
plausible_plausible  | 2024-05-22T19:51:21.286563768Z     ** (Protocol.UndefinedError) protocol Jason.Encoder not implemented for {:safe, ["<div class=\"container text-center mt-24\">\n  <h1 class=\"text-5xl font-black dark:text-gray-100\">", "406.json", "</h1>\n  <div class=\"my-4 text-xl dark:text-gray-100\">", "Not Acceptable", "</div>\n", [60, "a", [" class=\"", "button mt-4", 34, 32, "href", 61, 34, "/", 34], 62, "Go to the homepage", 60, 47, "a", 62], "\n</div>\n"]} of type Tuple, Jason.Encoder protocol must always be explicitly implemented. This protocol is implemented for the following type(s): Any, Atom, BitString, Cldr.LanguageTag, Date, DateTime, Decimal, Ecto.Association.NotLoaded, Ecto.Schema.Metadata, Float, Integer, Jason.Fragment, Jason.OrderedObject, List, Map, Money, NaiveDateTime, Plausible.Auth.Invitation, Plausible.Goal, Plausible.Site, Time
plausible_plausible  | 2024-05-22T19:51:21.286574088Z         (jason 1.4.0) lib/jason.ex:213: Jason.encode_to_iodata!/2
plausible_plausible  | 2024-05-22T19:51:21.286578088Z         (phoenix 1.7.2) lib/phoenix/controller.ex:1010: anonymous fn/5 in Phoenix.Controller.template_render_to_iodata/4
plausible_plausible  | 2024-05-22T19:51:21.286582368Z         (telemetry 1.2.1) /app/deps/telemetry/src/telemetry.erl:321: :telemetry.span/3
plausible_plausible  | 2024-05-22T19:51:21.286586328Z         (phoenix 1.7.2) lib/phoenix/controller.ex:976: Phoenix.Controller.render_and_send/4
plausible_plausible  | 2024-05-22T19:51:21.286598288Z         (phoenix 1.7.2) lib/phoenix/endpoint/render_errors.ex:84: Phoenix.Endpoint.RenderErrors.instrument_render_and_send/5
plausible_plausible  | 2024-05-22T19:51:21.286602929Z         (phoenix 1.7.2) lib/phoenix/endpoint/render_errors.ex:62: Phoenix.Endpoint.RenderErrors.__catch__/5
plausible_plausible  | 2024-05-22T19:51:21.286607729Z         (plug_cowboy 2.6.1) lib/plug/cowboy/handler.ex:11: Plug.Cowboy.Handler.init/2
plausible_plausible  | 2024-05-22T19:51:21.286612169Z         (cowboy 2.10.0) /app/deps/cowboy/src/cowboy_handler.erl:37: :cowboy_handler.execute/2
name: plausible
services:

# **************************************
# MAILSERVICE
# **************************************
  mail:
    image: sverzegnassi/smtp
    container_name: plausible_mail
    #image: bytemark/smtp
    restart: always
    env_file:
      - plausible-conf.env

# **************************************
# DATABASE
# **************************************
  plausible_db:
    image: postgres:14-alpine
    container_name: plausible_db
    restart: always
    volumes:
      - ./data/db-plausible:/var/lib/postgresql/data
    environment:
      - POSTGRES_PASSWORD=postgres

# **************************************
# EVENTS DATABASE
# **************************************
  plausible_events_db:
    image: clickhouse/clickhouse-server:23.3.7.5-alpine
    container_name: plausible_events_db
    restart: always
    volumes:
      - ./data/db-clickhouse:/var/lib/clickhouse
      - ./clickhouse/clickhouse-config.xml:/etc/clickhouse-server/config.d/logging.xml:ro
      - ./clickhouse/clickhouse-user-config.xml:/etc/clickhouse-server/users.d/logging.xml:ro
    ulimits:
      nofile:
        soft: 262144
        hard: 262144

# **************************************
# PLAUSIBLE SERVICE
# **************************************
  plausible:
    image: plausible/analytics:latest
    container_name: plausible_plausible
    restart: always
    command: sh -c "sleep 10 && /entrypoint.sh db createdb && /entrypoint.sh db
      migrate && /entrypoint.sh run"
    depends_on:
      - plausible_db
      - plausible_events_db
      - mail
    ports:
      - 127.0.0.1:8000:8000
    env_file:
      - plausible-conf.env

networks: {}
ruslandoga commented 4 months ago

👋 @wreidlinger

Do you use any plugins (e.g. WordPress)? Do you know what made that GET /api/plugins/v1/capabilities request?

ruslandoga commented 4 months ago

Off-topic, but note that TZ env vars are largely unnecessary in Plausible (tz is per site) and it might cause some problems when interpreting "naive" timestamps.

I'm not suggesting changing it, but just pointing it out as something to keep in mind if you ever encounter time-related problems :)

wreidlinger commented 4 months ago

Off-topic, but note that TZ env vars are largely unnecessary in Plausible (tz is per site) and it might cause some problems when interpreting "naive" timestamps.

I'm not suggesting changing it, but just pointing it out as something to keep in mind if you ever encounter time-related problems :)

@ruslandoga thanks for the hint. I have removed the TZ environment variables from the docker compose config. But the problem and the error still persists.

ruslandoga commented 4 months ago

TZ env var change was not supposed to fix the error :) Please see my first comment.

Whatever is making the request is not accepting JSON as the response (it doesn't have accept: application/json header). I'll check if the error message could be improved. And note that GET /api/plugins/v1/capabilities is mostly a health-check endpoint, it doesn't affect visitor tracking (that goes into POST /api/event)

wreidlinger commented 4 months ago

👋 @wreidlinger

Do you use any plugins (e.g. WordPress)? Do you know what made that GET /api/plugins/v1/capabilities request?

Yes you are right. The domain having problems with tracking is a Wordpress site and is using the Plausible Analytics Wordpress plugin. Furthermore this Wordpress site is also running in a docker compose stack on the same virtual server as the Plausible stack is running.

Just a side info... the Plausible as well as the Wordpress stack using a Caddy webserver as there reverse proxy.

Here is the error log of the Caddy webserver for the plausible domain. To me it seams that these to error logs correlate. Looks like the internal docker IP of the Wordpress container is used for the request from the Wordpress to the Plausible stack. Strange... I'm trying to fix this issue.

{
  "level": "error",
  "ts": "2024/05/23 09:54:15",
  "logger": "http.log.access.log5",
  "msg": "handled request",
  "request": {
    "remote_ip": "172.26.0.5",
    "remote_port": "38662",
    "client_ip": "172.26.0.5",
    "proto": "HTTP/1.1",
    "method": "GET",
    "host": "plausible.mydomain.com",
    "uri": "/api/plugins/v1/capabilities",
    "headers": {
      "User-Agent": [
        "OpenAPI-Generator/1.0.0/PHP"
      ],
      "Accept": [
        "application/json"
      ],
      "Content-Type": [
        "application/json"
      ],
      "Authorization": []
    },
    "tls": {
      "resumed": false,
      "version": 772,
      "cipher_suite": 4865,
      "proto": "http/1.1",
      "server_name": "plausible.mydomain.com"
    }
  },
  "bytes_read": 0,
  "user_id": "",
  "duration": 0.00428649,
  "size": 0,
  "status": 500,
  "resp_headers": {
    "Server": [
      "Caddy"
    ],
    "Alt-Svc": [
      "h3=\":443\"; ma=2592000"
    ],
    "Content-Length": [
      "0"
    ]
  }
}