Kolibri login works, but content access causes crash

If you have a specific technical inquiry, construct your post with the following:

Summary

Users can log into Kolibri, navigate through the folders, but when clicking a tile that leads into learning content, Kolibri crashes with the error below.

I have not updated content for a number of weeks, nor did I do an update of Kolibri. I did do an update of the RPi over the weekend, but the users today told me that this problem started last Friday (they didn’t tell me until Monday afternoon when they came back to start studying…).

It seems that it is not all content that causes the crash, but most. Also, upon clicking the Channels" tab, it crashed and went to a Server Error (500).

I have both restarted Kolibri and Kolibri server, and have also reboot the RPi.

Checking Kolibri server status, it reported it was inactive. I restarted it. It now reports it is running. However, the error continues.

Error reported:
{
“data”: “

Server Error (500)

”,
“status”: 500,
“statusText”: “Internal Server Error”,
“headers”: {
“connection”: “keep-alive”,
“content-type”: “text/html”,
“date”: “Mon, 21 Sep 2020 13:35:22 GMT”,
“server”: “nginx/1.14.2”,
“transfer-encoding”: “Identity”
},
“config”: {
“url”: “/api/content/contentnode/”,
“params”: {
“ids”: [
“e3d5255c42cb43b3977a74142b892d12”,
“de713221436a4bd2ac5700886945e989”,
“228643f849574d398292132665899753”,
“cd03e7039c684b2f84e7c50c601cc21f”,
“09b44fa67eae4883bb97a9ae4732b9bf”,
“56d0622c3e934ac08d6fffb3338262ec”,
“86dd798011ce4c9eb3588ee79e151901”,
“98927ec2c8f847f99d39dab1ee6778e2”,
“36efb7a7fa1f4900926b52e0311c959d”,
“7a06d0d3d1054d5b8620aebc92460bfe”,
“5f1cd5c56ebf4cd3900d6d34de40881a”,
“4f7906abef2a410d8cc197a9841f088f”,
“6adcdffe05634f48815c9d4e841d6f8d”,
“9b642dfc5f72462a8d13aabaa5f080b0”,
“a3b61e4c06784b2aa9f50fc38f7dc192”,
“29130fab878f4cd9b597bfdf9790949f”,
“22409f9da7134ff5a27a8d9ee4cf7af6”,
“0c3c8ec757f048128c5a10e4cfd412f5”,
“5de1cf51ad6549a686676d0f65c5ec44”,
“42cc26174e964033b35fba40cc83dd2c”,
“888c68a4e4994c38abc2505ca03291cf”,
“a9a6206d8a1b4a5fa63db95c78573891”,
“4a06b84b77fd43a586e28e2213ae5126”,
“b9333e5864764ef89214c8b1989df7c4”,
“fc698935e6cf450a8a6bc0a271c72880”,
“b296c0cf64a44484b7bb9924ef16eacc”,
“bb29b99638fb416d8894fe816c41658c”,
“79821cdd9dc3494a816b512a025d397b”,
“ac1b81257e884476bae7a1e76c96ab8f”,
“9c0f8a59c50b4f549252a1c1564b06df”,
“6b96e41864ed4b63a3bf5a6e231e546e”,
“2866953bd5354d808cc7fbe71cd9c369”,
“6906fb336112443985ca5f8efab76234”,
“8606aa01d12448d89ac13de3545cb948”,
“62c280059f324d188749a707d5feff58”,
“bd88be2a4d7e4a5fba50bb76dbdd393d”,
“2db04e71dd9f48809a5458e92c1b94b6”,
“a3819a22f2354273a5be8c67e340029a”,
“8bbf6c1ef70649cca6da055eded02b7b”,
“164dcc5ece8d4dae9cf3a334ed6e4b53”,
“077e06e47c87433e9330ed8b6f8e1e15”,
“dd0ebe7be85f4b03aeabb4864909d187”
],
“contentCacheKey”: 1597425071
},
“headers”: {
“Accept”: “application/json, text/plain, /”,
“X-Requested-With”: “XMLHttpRequest”,
“X-CSRFToken”: “BEb1XwYGiH5vTPkSiJ0Wdms0GRItTCTNXDcCjJtpF7hUrSRk5W26J64tqoLZjk0e”
},
“transformRequest”: [
null
],
“transformResponse”: [
null
],
“timeout”: 0,
“xsrfCookieName”: “kolibri_csrftoken”,
“xsrfHeaderName”: “X-CSRFToken”,
“maxContentLength”: -1,
“cacheBust”: false,
“method”: “get”
},
“request”: {}
}

Technical details

Version: 0.14.3
OS: Linux-5.4.51-v7±armv7l-with-debian-10.4
Python: 3.7.3
Installer: kolibri(apt) with kolibri-server Version: 0.3.6-0ubuntu1
Server: nginx/1.14.2
Database: /home/pi/.kolibri/db.sqlite3
Free disk space: 183 GB
Server time: Mon Sep 21 2020 14:43:03 GMT+0100 (WAT)
Server timezone: Africa/Douala

Here is additional info copied from the kolibri.txt log file:

WARNING 2020-09-21 14:49:07,957 kolibri.core.discovery.utils.network.search
A new Kolibri instance ‘c827522bb6bdec5058f548dd282a2423-2’ was seen on the zeroconf network,
but we had trouble getting the information we needed about it.
Service info:
{‘id’: ‘c827522bb6bdec5058f548dd282a2423-2’, ‘ip’: ‘127.0.0.1’, ‘local’: True, ‘port’: 80, ‘host’: ‘c827522bb6bdec5058f548dd282a2423-2.kolibri.local’, ‘base_url’: ‘http://127.0.0.1:80/’, ‘self’: False, ‘application’: ‘kolibri’, ‘kolibri_version’: ‘0.14.3’, ‘instance_id’: ‘c827522bb6bdec5058f548dd282a2423’, ‘device_name’: ‘raspberrypi’, ‘operating_system’: ‘Linux’}
The following exception was raised:
Traceback (most recent call last):
File “/usr/lib/python3/dist-packages/kolibri/dist/django/db/models/query.py”, line 480, in update_or_create
obj = self.select_for_update().get(**lookup)
kolibri.core.discovery.models.DoesNotExist: DynamicNetworkLocation matching query does not exist.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File “/usr/lib/python3/dist-packages/kolibri/core/discovery/utils/network/search.py”, line 148, in add_service
dict(base_url=base_url, **device_info), id=id
django.core.exceptions.ValidationError: {‘instance_id’: [’instance_id and id must be the same’]}

INFO 2020-09-21 14:49:08,116 cherrypy.access 10.0.2.2 - - “GET /en/learn/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,272 cherrypy.access 10.0.2.2 - - “GET /api/auth/session/current/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,318 cherrypy.error ENGINE Bus STARTED
INFO 2020-09-21 14:49:08,358 cherrypy.access 10.0.2.2 - - “GET /api/notifications/pingbacknotification/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,378 cherrypy.access 10.0.2.2 - - “GET /api/auth/membership/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,432 cherrypy.access 10.0.2.2 - - “GET /api/auth/facility/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,481 cherrypy.access 10.0.2.2 - - “GET /api/auth/facilitydataset/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,686 cherrypy.access 10.0.2.2 - - “GET /api/auth/facilityuser/1d108bdd462c31595ae8bb2e8f72d7b8/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:08,751 cherrypy.access 10.0.2.2 - - “GET /api/logger/userprogress/1d108bdd462c31595ae8bb2e8f72d7b8/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:09,139 cherrypy.access 10.0.2.2 - - “GET /learn/api/learnerclassroom/” 200 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”
INFO 2020-09-21 14:49:10,192 kolibri.core.analytics.utils Ping succeeded! (response: {‘id’: 1055662, ‘messages’: })
ERROR 2020-09-21 14:49:10,873 django.request Internal Server Error: /api/content/channel/
Traceback (most recent call last):
File “/usr/lib/python3/dist-packages/kolibri/dist/django/core/handlers/exception.py”, line 41, in inner
response = get_response(request)
File “/usr/lib/python3/dist-packages/kolibri/dist/django/utils/deprecation.py”, line 142, in call
response = self.process_response(request, response)
File “/usr/lib/python3/dist-packages/kolibri/dist/django/middleware/cache.py”, line 102, in process_response
lambda r: self.cache.set(cache_key, r, timeout)
File “/usr/lib/python3/dist-packages/kolibri/dist/django/template/response.py”, line 94, in add_post_render_callback
callback(self)
File “/usr/lib/python3/dist-packages/kolibri/dist/django/middleware/cache.py”, line 102, in
lambda r: self.cache.set(cache_key, r, timeout)
File “/usr/lib/python3/dist-packages/kolibri/dist/redis_cache/backends/base.py”, line 30, in wrapped
return method(self, client, key, *args, **kwargs)
File “/usr/lib/python3/dist-packages/kolibri/dist/redis_cache/backends/base.py”, line 274, in set
result = self._set(client, key, self.prep_value(value), timeout, _add_only=False)
File “/usr/lib/python3/dist-packages/kolibri/dist/redis_cache/backends/base.py”, line 267, in _set
return client.set(key, value, nx=_add_only, ex=timeout)
File “/usr/lib/python3/dist-packages/kolibri/dist/redis/client.py”, line 1451, in set
return self.execute_command(‘SET’, *pieces)
File “/usr/lib/python3/dist-packages/kolibri/dist/redis/client.py”, line 775, in execute_command
return self.parse_response(connection, command_name, **options)
File “/usr/lib/python3/dist-packages/kolibri/dist/redis/client.py”, line 789, in parse_response
response = connection.read_response()
File “/usr/lib/python3/dist-packages/kolibri/dist/redis/connection.py”, line 642, in read_response
raise response
redis.exceptions.ResponseError: OOM command not allowed when used memory > ‘maxmemory’.
INFO 2020-09-21 14:49:13,892 cherrypy.access 10.0.2.2 - - “GET /api/content/channel/” 500 0 “http://kolibri.jv/en/learn/” “Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0 Safari/605.1.15”

I believe that I have solved this problem myself. Looking at the end of the content from the kolibri log file, I noticed there was a “maxmemory” issue with redis. I remembered that @jredrejo told me how to clear the redis memory:

log into the command line of kolibri
enter: redis-cli
enter: flushdb
enter: exit

Seems to have addressed the problem.

Hi Chris,

Could you look in the ./kolibri/options.ini file to see what the current value of CACHE_REDIS_MAXMEMORY is? José suggests setting it to a large number like 9000000 (9 with 6 zeroes) might help prevent this in the longer term.

The maxmemory size is already set higher than that. The contents of the options.ini file are below:

[Paths]
CONTENT_DIR = /KOLIBRI_DATA/content
CONTENT_FALLBACK_DIRS = /home/pi/.kolibri/,
[Cache]
CACHE_BACKEND = redis
CACHE_REDIS_MAXMEMORY = 136000000
[Server]
CHERRYPY_START = False
[Deployment]
HTTP_PORT = 80
URL_PATH_PREFIX = /
[Database]
[Urls]
[Python]
[HTML5]
SANDBOX = allow-scripts

@jonathan I wonder if there is an automated way that the redis cache can be cleared on a regular basis. A cron job? Or something else? I’m thinking about this in that we want to install Kolibri servers in some village locations where getting to them for technical support will be difficult. Also, there wouldn’t easily be anyone for local, technical support. This redis cache problem has come up a number of times for me before. I just happened to remember it this time around and was able to clear the problem.

Hello @cjackson,
yes, there is a serie of new optional parameters to add to the options.ini file to make redis reduce automatically the size of the caching thus avoiding problems in low memory devices.
They are set under the [Cache] section in the .kolibri/options.ini file with these default values:.
[Cache]
CACHE_REDIS_MAXMEMORY=0
CACHE_MAX_ENTRIES=1000
CACHE_REDIS_MAX_POOL_SIZE=50
CACHE_REDIS_MAXMEMORY_POLICY=""
are the ones that could be useful for you. I would not play with them all at the same time, in your case I think that CACHE_REDIS_MAXMEMORY should be the only to try to fine tune.
In any case, I think the problem you had yesterday was due to a bad upgrade from a beta version to the final 0.14.3 release and it should not happen any more if you set a value for CACHE_REDIS_MAXMEMORY after flushing its database.
The default value for this parameter is 0, what means no limit, and for a 1Gb of RAM device, that’s not good.

If you have this problem again after this change, we should investigate it more, because it would be an issue that must be fixed.
José