grafana-source-relation-changed hook fails due to empty DB

Bug #1797605 reported by Michael Skalka
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Grafana Charm
Won't Fix
Undecided
Unassigned

Bug Description

In a deployment of Grafana using the latest charm (rev 20) on 16.04 deployed into AWS the grafana-source-relation-changed hook fails due to a missing table. The charm is using only the default options specified in the charm config.

### /var/log/juju/unit-grafana-0.log ###
2018-10-12 17:03:41 INFO juju-log grafana-source:21: Found datasource: {'description': 'Juju generated source', 'service_name': 'prometheus', 'url': 'http://172.25.10.209:9090', 'type': 'prometheus'}
2018-10-12 17:03:41 ERROR juju-log grafana-source:21: Hook error:
Traceback (most recent call last):
  File "/var/lib/juju/agents/unit-grafana-0/.venv/lib/python3.5/site-packages/charms/reactive/__init__.py", line 73, in main
    bus.dispatch(restricted=restricted_mode)
  File "/var/lib/juju/agents/unit-grafana-0/.venv/lib/python3.5/site-packages/charms/reactive/bus.py", line 382, in dispatch
    _invoke(other_handlers)
  File "/var/lib/juju/agents/unit-grafana-0/.venv/lib/python3.5/site-packages/charms/reactive/bus.py", line 358, in _invoke
    handler.invoke()
  File "/var/lib/juju/agents/unit-grafana-0/.venv/lib/python3.5/site-packages/charms/reactive/bus.py", line 180, in invoke
    self._action(*args)
  File "/var/lib/juju/agents/unit-grafana-0/charm/reactive/grafana.py", line 389, in configure_sources
    check_datasource(ds)
  File "/var/lib/juju/agents/unit-grafana-0/charm/reactive/grafana.py", line 482, in check_datasource
    query = cur.execute('SELECT id, type, name, url, is_default FROM DATA_SOURCE')
sqlite3.OperationalError: no such table: DATA_SOURCE

It appears as though the database Grafana is using is completely empty:

### grafana/0 ###
root@ip-172-XX-XX-XXX:~# ls -al /var/lib/grafana/
total 8
drwxr-xr-x 2 grafana grafana 4096 Oct 12 16:14 .
drwxr-xr-x 49 root root 4096 Oct 10 19:52 ..
-rw-r--r-- 1 root root 0 Oct 12 16:14 grafana.db

We also see errors in journalctl about the database being read-only:

### grafana/0 ###
root@ip-172-25-11-89:~# journalctl -xe
...
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: Started Grafana instance.
-- Subject: Unit grafana-server.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit grafana-server.service has finished starting up.
--
-- The start-up result is done.
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Starting Grafana" logger=server version=5.3.0 commit=c613a31 compiled=2018-10-10T10:20:21+0000
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Config loaded from" logger=settings file=/usr/share/grafana/conf/defaults.ini
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Config loaded from" logger=settings file=/etc/grafana/grafana.ini
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Config overridden from command line" logger=settings arg="default.paths.data=/var/lib/grafana"
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Config overridden from command line" logger=settings arg="default.paths.logs=/var/log/grafana"
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Config overridden from command line" logger=settings arg="default.paths.plugins=/var/lib/grafana/plugins"
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Config overridden from command line" logger=settings arg="default.paths.provisioning=/etc/grafana/provisioning"
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Path Home" logger=settings path=/usr/share/grafana
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Path Data" logger=settings path=/var/lib/grafana
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Path Logs" logger=settings path=/var/log/grafana
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Path Plugins" logger=settings path=/var/lib/grafana/plugins
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Path Provisioning" logger=settings path=/etc/grafana/provisioning
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="App mode production" logger=settings
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Writing PID file" logger=server path=/var/run/grafana/grafana-server.pid pid=27828
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Initializing SqlStore" logger=server
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Connecting to DB" logger=sqlstore dbtype=sqlite3
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Starting DB migration" logger=migrator
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=info msg="Executing migration" logger=migrator id="create migration_log table"
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=eror msg="Executing migration failed" logger=migrator id="create migration_log table" error="attempt to write a readonly database"
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=eror msg="Exec failed" logger=migrator error="attempt to write a readonly database" sql="CREATE TABLE IF NOT EXISTS `migration_log` (\n`id` INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL\n, `migration_id` TEXT NOT NULL\n, `s
Oct 12 16:56:45 ip-172-25-11-89 grafana-server[27828]: t=2018-10-12T16:56:45+0000 lvl=eror msg="Server shutdown" logger=server reason="Service init failed: Migration failed err: attempt to write a readonly database"
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: grafana-server.service: Main process exited, code=exited, status=1/FAILURE
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: grafana-server.service: Unit entered failed state.
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: grafana-server.service: Failed with result 'exit-code'.
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: grafana-server.service: Service hold-off time over, scheduling restart.
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: Stopped Grafana instance.
-- Subject: Unit grafana-server.service has finished shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit grafana-server.service has finished shutting down.
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: grafana-server.service: Start request repeated too quickly.
Oct 12 16:56:45 ip-172-25-11-89 systemd[1]: Failed to start Grafana instance.
-- Subject: Unit grafana-server.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit grafana-server.service has failed.
--
-- The result is failed.
...

This issue persists across redeploys.

Revision history for this message
Michael Skalka (mskalka) wrote :
Revision history for this message
Wouter van Bommel (woutervb) wrote :

This appears more as a system issue then something the charm has done

Changed in charm-grafana:
status: New → Won't Fix
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Bug attachments

Remote bug watches

Bug watches keep track of this bug in other bug trackers.