search

fr-ser / grafana-sqlite-datasource

Grafana Plugin to enable SQLite as a Datasource
Apache License 2.0
123 stars 17 forks source link

Docker: Could not start plugin - Unrecognized remote plugin message #94

Closed sensej-j closed 1 year ago

sensej-j commented 1 year ago

Error Plugin unavailable when trying to save and test data source.

image

image

image

Grafana-Docker-Log

logger=context traceID=00000000000000000000000000000000 userId=1 orgId=1 uname=admin t=2022-07-29T14:29:00.794365614Z level=error msg="Plugin unavailable" error="plugin unavailable" remote_addr=192.168.178.51 traceID=00000000000000000000000000000000

logger=context traceID=00000000000000000000000000000000 userId=1 orgId=1 uname=admin t=2022-07-29T14:29:00.794732911Z level=error msg="Request Completed" method=GET path=/api/datasources/1/health status=503 remote_addr=192.168.178.51 time_ms=8 duration=8.528612ms size=77 referer=http://192.168.178.3:3001/datasources/edit/dpxzCIzVz traceID=00000000000000000000000000000000

Notice: In Grafana 8.4.1 the tool works

fr-ser commented 1 year ago
  • Grafana Version: 9.0.5
  • Plugin Version: 3.1.1
  • Plugin installed via: grafana-cli plugins install frser-sqlite-datasource or Grafana/Plugins -> Install

Notice: In Grafana 8.4.1 the tool works

While the plugin is not (yet) officially tested against Grafana version 9 I just ran it locally and everything worked for me. Since you see it working against a different Grafana version I would be interested if the two environments (with the different Grafana versions) are differing in some regards.

If that does not solve the issue, could you provide some more logs? A whole log from startup from Grafana on DEBUG level would be best

sensej-j commented 1 year ago

ok, i check it again

sensej-j commented 1 year ago

I can't find any mistake. All file rights checked Grafana container restarted multiple times

Installed the tool(frser-sqlite-datasource) in locally Grafana on my Windows: is working

maybe this error message will help

Log 2022-08-01T16:58:46.905453147+02:00 logger=plugin.manager t=2022-08-01T14:58:46.904520501Z level=error msg="Could not start plugin" pluginId=frser-sqlite-datasource err="Unrecognized remote plugin message: \n\nThis usually means that the plugin is either invalid or simply\nneeds to be recompiled to support the latest protocol.", 2022-08-01T16:58:46.905536719+02:00 logger=plugin.manager t=2022-08-01T14:58:46.904894789Z level=error msg="Could not start plugin" pluginId=frser-sqlite-datasource err="plugin frser-sqlite-datasource is already registered", 2022-08-01T16:58:46.907390398+02:00 logger=secrets t=2022-08-01T14:58:46.906974404Z level=info msg="Envelope encryption state" enabled=true currentprovider=secretKey.v1, 2022-08-01T16:58:46.929960813+02:00 logger=query_data t=2022-08-01T14:58:46.929297549Z level=info msg="Query Service initialization",

sensej-j commented 1 year ago

Installed the tool(frser-sqlite-datasource) in locally Grafana on my Windows: is working

I need the tool in Docker, what else can I check?

fr-ser commented 1 year ago

2022-08-01T16:58:46.905453147+02:00 logger=plugin.manager t=2022-08-01T14:58:46.904520501Z level=error msg="Could not start plugin" pluginId=frser-sqlite-datasource err="Unrecognized remote plugin message: \n\nThis usually means that the plugin is either invalid or simply\nneeds to be recompiled to support the latest protocol." 2022-08-01T16:58:46.905536719+02:00 logger=plugin.manager t=2022-08-01T14:58:46.904894789Z level=error msg="Could not start plugin" pluginId=frser-sqlite-datasource err="plugin frser-sqlite-datasource is already registered" 2022-08-01T16:58:46.907390398+02:00 logger=secrets t=2022-08-01T14:58:46.906974404Z level=info msg="Envelope encryption state" enabled=true currentprovider=secretKey.v1, 2022-08-01T16:58:46.929960813+02:00 logger=query_data t=2022-08-01T14:58:46.929297549Z level=info msg="Query Service initialization",

That does look like a problem indeed. Could you share the whole debug log from start until you try in the Grafana UI? This could give some more context

I need the tool in Docker, what else can I check?

The tool should definitely work in Docker. Could you maybe share your docker setup so I can try to reproduce the issue (e.g. Dockerfile, docker-compose.yaml, startup command of the container, etc.)?

sensej-j commented 1 year ago

Here are the portainer-settings

image

image

image

image

fr-ser commented 1 year ago

It looks like you are using some UI, sadly. If you can provide me with a Dockerfile and/or a docker-compose.yaml, that reproduces the issue it would help immensely. Without that and further logs I don't think I have any other clues.

sensej-j commented 1 year ago

Hello Sergej, unfortunately I don't have access to docker on the smart home server. I can only create the containers using Portainer GUI. Which logs do you mean? I only have the log entries in Grafana Portainer.

fr-ser commented 1 year ago

Hello Sergej, unfortunately I don't have access to docker on the smart home server. I can only create the containers using Portainer GUI.

That makes recreating the issue a bit more difficult but can't be helped I assume. How do you install the plugin in the container, though? Can you log into the container?

Which logs do you mean? I only have the log entries in Grafana Portainer.

Those are the logs I mean. But it would help to have the full logs from startup up at the DEBUG level (and above) instead of just the two lines you provided.

sensej-j commented 1 year ago

How do you install the plugin in the container, though? Can you log into the container?

Option 1: Portainer-Console image

image

image

Option 2: Grafana GUI

up at the DEBUG level

I only have this option

image

Here is the log file

Grafana_9.0.5.log

Grafana_9.0.5_With_Deinstall_and_Install_SQL-Plugin.log.txt

fr-ser commented 1 year ago

The log files are not actually at debug level I believe. You can check this link for details how to enable debug logging: https://grafana.com/docs/grafana/latest/setup-grafana/configure-grafana/#log

Can you also try another version of Grafana (inside the docker environment). I would like to find out if the version of Grafana/the plugin is the problem or if it is because it is running in the docker environment.

sensej-j commented 1 year ago

Here are two log files.

Grafana Docker Version 8.4.1: Everything works there

Grafana Docker Version 9.0.5: Error Plugin unavailable

Grafana_Docker_8.4.1_Level_Debug_OK_13.08.2022.txt

Grafana_Docker_9.0.5_Level_Debug_Error_13.08.2022.txt

fr-ser commented 1 year ago

Thank you for the log files! Sadly I don't have any more clues from those.

Can you do the following:

  1. Uninstall the plugin from the container (if it is still installed) and install it using the environment variable GF_INSTALL_PLUGINS=frser-sqlite-datasource 3.1.0 (see link)

  2. Could you give me some more information about your setup, so I can try reproducing it.

    • What is the operating system/machine of the host PC (are you running on a windows laptop, raspberry pi, ...)
    • You are running something called "portainer". I am not familiar with the tool. Is it running any abstractions? E.g. running the docker container in some virtual machine?
sensej-j commented 1 year ago

Notice

I have tested up to version 9.1.0. Everything is fine up to Grafana version 9.0.4 The error occurs from Grafana version 9.0.5 to 9.1.0

Uninstall the plugin from the container (if it is still installed) and install it using the environment variable

Here are the logs from grafana-installing with GF_INSTALL_PLUGINS = frser-sqlite-datasource 3.1.0 GF_LOG_CONSOLE_LEVEL = debug

Log_Grafana_Install_V9.0.4_Level_Debug_OK_17.08.2022.txt

Log_Grafana_Install_V9.0.7_Level_Debug_Error_17.08.2022.txt line: 3424 2022-08-17T11:48:04.585623698+02:00 logger=plugin.frser-sqlite-datasource t=2022-08-17T09:48:04.584459049Z level=debug msg="runtime/cgo: pthread_create failed: Operation not permitted"

line: 3733 2022-08-17T11:48:04.596905051+02:00 logger=plugin.manager t=2022-08-17T09:48:04.595991268Z level=error msg="Could not start plugin" pluginId=frser-sqlite-datasource err="Unrecognized remote plugin message: \n\nThis usually means that the plugin is either invalid or simply\nneeds to be recompiled to support the latest protocol."

What is the operating system/machine of the host PC (are you running on a windows laptop, raspberry pi, ...)

host op: Debian Stretch (9.13) host machine cpu: 64 Bit Quad-Core 1 GHz host Docker version: 19.03.15 host portainer version: 1.17.1

You are running something called "portainer". I am not familiar with the tool. Is it running any abstractions? E.g. running the docker container in some virtual machine?

https://hub.docker.com/r/portainer/portainer https://docs.portainer.io/

danieltdt commented 1 year ago

I'm facing the same problem for the official grafana Alpine images... I believe this plugins needs a precompile alpine version to work.

fr-ser commented 1 year ago

I'm facing the same problem for the official grafana Alpine images

That is an interesting observation. I'll try that out and see what might be the issue there.

fr-ser commented 1 year ago

I'm facing the same problem for the official grafana Alpine images... I believe this plugins needs a precompile alpine version to work.

Hello @danieltdt, I couldn't reproduce the issue. Could you share your setup so I can see the problem you are facing? @sensej-j : On the off chance that is it alpine related could you try this grafana image "grafana/grafana:9.0.5-ubuntu" instead of "grafana/grafana:9.0.5"

sensej-j commented 1 year ago

I tried the grafana/grafana:9.1.4-ubuntu version today and everything works again

danieltdt commented 1 year ago

I'm facing the same problem for the official grafana Alpine images... I believe this plugins needs a precompile alpine version to work.

Hello @danieltdt, I couldn't reproduce the issue. Could you share your setup so I can see the problem you are facing?

Don't know exactly how, but now the latest docker alpine version is working for me too 🤷🏼

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

DesistDaydream commented 1 year ago

Version

OS: Ubuntu 20.04TLS Docker: 20.10.9 Plugin: 3.1.0 Grafana: 9.1.6

docker-compose

  grafana:
    container_name: grafana
    image: grafana/grafana:9.1.6
    network_mode: host
    restart: always
    user: "472"
    volumes:
      - ./config/grafana:/etc/grafana
      - ./data/grafana:/var/lib/grafana
      - /etc/localtime:/etc/localtime

Debug log

logger=accesscontrol.evaluator t=2022-10-17T16:16:19.596133248+08:00 level=debug msg="matched scope" userscope=datasources:* targetscope=datasources:uid:Kef7VLI4z
logger=datasources t=2022-10-17T16:16:19.596222283+08:00 level=debug msg="Received command to update data source" url=
logger=datasource t=2022-10-17T16:16:19.596234114+08:00 level=debug msg="Applying default URL parsing for this data source type" type=frser-sqlite-datasource url=
logger=datasource t=2022-10-17T16:16:19.596239536+08:00 level=debug msg="Data source URL doesn't specify protocol, so prepending it with http:// in order to make it unambiguous" type=frser-sqlite-datasource url=
logger=sqlstore.session t=2022-10-17T16:16:19.596490686+08:00 level=debug msg="reusing existing session" transaction=true
logger=sqlstore.session t=2022-10-17T16:16:19.596855084+08:00 level=debug msg="reusing existing session" transaction=true
logger=secrets.kvstore t=2022-10-17T16:16:19.602398839+08:00 level=debug msg="got secret value" orgId=1 type=datasource namespace=DTCG
logger=sqlstore.session t=2022-10-17T16:16:19.602430369+08:00 level=debug msg="reusing existing session" transaction=true
logger=sqlstore.session t=2022-10-17T16:16:19.6080399+08:00 level=debug msg="reusing existing session" transaction=true
logger=secrets.kvstore t=2022-10-17T16:16:19.60823125+08:00 level=debug msg="secret value updated" orgId=1 type=datasource namespace=DTCG
logger=sqlstore.transactions t=2022-10-17T16:16:19.608242814+08:00 level=debug msg="skip committing the transaction because it belongs to a session created in the outer scope"
logger=sqlstore.transactions t=2022-10-17T16:16:19.608249226+08:00 level=debug msg="skip committing the transaction because it belongs to a session created in the outer scope"
logger=secrets.kvstore t=2022-10-17T16:16:19.61299092+08:00 level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=DTCG
logger=accesscontrol.evaluator t=2022-10-17T16:16:19.766568103+08:00 level=debug msg="matched scope" userscope=datasources:* targetscope=datasources:uid:Kef7VLI4z
logger=secrets.kvstore t=2022-10-17T16:16:19.766920059+08:00 level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=DTCG
logger=datasources t=2022-10-17T16:16:19.830375003+08:00 level=debug msg="Querying for data source via SQL store" id=4 orgId=1
logger=secrets.kvstore t=2022-10-17T16:16:19.830719693+08:00 level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=DTCG
logger=context traceID=00000000000000000000000000000000 userId=1 orgId=1 uname=admin t=2022-10-17T16:16:19.830762706+08:00 level=error msg="Plugin unavailable" error="plugin unavailable" remote_addr=192.168.0.249 traceID=00000000000000000000000000000000
logger=context traceID=00000000000000000000000000000000 userId=1 orgId=1 uname=admin t=2022-10-17T16:16:19.830803563+08:00 level=error msg="Request Completed" method=GET path=/api/datasources/4/health status=503 remote_addr=192.168.0.249 time_ms=1 duration=1.262051ms size=77 referer=https://lch-grafana.102205.xyz:8443/datasources/edit/Kef7VLI4z traceID=00000000000000000000000000000000 handler=/api/datasources/:id/health
logger=ngalert t=2022-10-17T16:16:20.000970883+08:00 level=debug msg="alert rules fetched" count=0