Hi all. I have some weird behaviour on a Graylog 4 cluster. I’ve seen other support posts that have the specific stacktrace message in, but never an actual solution. Hoping the community can help this time around!
1. Describe your incident:
We have a graylog 4 / elasticsearch-oss 7 cluster that we use internally. It’s not strictly speaking production/customer facing but I would like to avoid rebuilding it if possible. There are 4 servers involved, all on the same subnet with no network restrictions between.
Server 1 - Graylog, haproxy, mongodb primary
Server 2 - Graylog, haproxy, mongodb secondary
Server 3 - elasticsearch, mongodb arbiter
Server 4 - elasticsearch
I hadn’t logged into the system in a while - all servers receive updated packages via the usual apt repositories so it’s possible a few minor version upgrades took place during this time when it was working. However I’ve been unable to log in to it recently, the web interface gives a 500 internal server error when creating the session. I’ve discovered that if I drop the sessions collection from mongodb, I can log in once. Then the next time I go to log in (as any user) the 500 internal server error is back.
2. Describe your environment:
-
OS Information:
Ubuntu 20.04.06 LTS - I am aware this is out of support
Kernel 5.4.0-153-generic -
Package Version:
graylog-server/stable,now 4.3.15-1
mongodb-org/focal,now 4.4.23
elasticsearch-oss/now 7.10.2 amd64 -
Service logs, configurations, and environment variables:
This is the mongodb connection string in the graylog configuration:
mongodb_uri = mongodb://server1:27017,server2:27017,server3:27017/graylog?replicaSet=rs0&readPreference=primaryPreferred&w=1&journal=true&wtimeoutMS=5000
This is the stacktrace from graylog when attempting to log in a second time after a successful first login. The ‘BasicDBObject cannot be cast to [B’ is one I have seen before in support posts.
2023-07-20T09:27:16.543Z ERROR [AnyExceptionClassMapper] Unhandled exception in REST resource
java.lang.RuntimeException: Couldn't load session
at org.graylog2.security.MongoDbSessionDAO.doUpdate(MongoDbSessionDAO.java:101) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.eis.CachingSessionDAO.update(CachingSessionDAO.java:277) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.DefaultSessionManager.onChange(DefaultSessionManager.java:212) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.AbstractNativeSessionManager.applyGlobalSessionTimeout(AbstractNativeSessionManager.java:125) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.AbstractNativeSessionManager.start(AbstractNativeSessionManager.java:100) ~[graylog.jar:?]
at org.apache.shiro.mgt.SessionsSecurityManager.start(SessionsSecurityManager.java:152) ~[graylog.jar:?]
at org.apache.shiro.subject.support.DelegatingSubject.getSession(DelegatingSubject.java:340) ~[graylog.jar:?]
at org.apache.shiro.subject.support.DelegatingSubject.getSession(DelegatingSubject.java:316) ~[graylog.jar:?]
at org.graylog2.shared.security.SessionCreator.login(SessionCreator.java:85) ~[graylog.jar:?]
at org.graylog2.rest.resources.system.SessionsResource.newSession(SessionsResource.java:142) ~[graylog.jar:?]
at sun.reflect.GeneratedMethodAccessor180.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_362]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_362]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391) ~[graylog.jar:?]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80) ~[graylog.jar:?]
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:255) [graylog.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) [graylog.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) [graylog.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) [graylog.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) [graylog.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) [graylog.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265) [graylog.jar:?]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:234) [graylog.jar:?]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680) [graylog.jar:?]
at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer.service(GrizzlyHttpContainer.java:356) [graylog.jar:?]
at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:200) [graylog.jar:?]
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:180) [graylog.jar:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_362]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_362]
at java.lang.Thread.run(Thread.java:750) [?:1.8.0_362]
2023-07-20T09:28:49.735Z ERROR [ExecutorServiceSessionValidationScheduler] Error while validating the session
java.lang.ClassCastException: com.mongodb.BasicDBObject cannot be cast to [B
at org.graylog2.security.MongoDbSession.getAttributes(MongoDbSession.java:69) ~[graylog.jar:?]
at org.graylog2.security.MongoDbSessionDAO.getSimpleSession(MongoDbSessionDAO.java:92) ~[graylog.jar:?]
at org.graylog2.security.MongoDbSessionDAO.getActiveSessions(MongoDbSessionDAO.java:156) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.DefaultSessionManager.getActiveSessions(DefaultSessionManager.java:244) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.AbstractValidatingSessionManager.validateSessions(AbstractValidatingSessionManager.java:280) ~[graylog.jar:?]
at org.apache.shiro.session.mgt.ExecutorServiceSessionValidationScheduler.run(ExecutorServiceSessionValidationScheduler.java:120) [graylog.jar:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_362]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_362]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_362]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_362]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_362]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_362]
at java.lang.Thread.run(Thread.java:750) [?:1.8.0_362]
Haproxy sees the request with nothing to suggest it is doing anything with it other than proxying it as expected:
Jul 20 09:42:02 server1 haproxy[945]: w.x.y.z:61133 [20/Jul/2023:09:42:02.230] graylog_https_fe~ graylog_https_be/graylog1 0/0/15/14/29 500 272 - - ---- 1/1/0/0/0 0/0 "POST /api/system/sessions HTTP/1.1"
Nothing is recorded in the MongoDB log file.
3. What steps have you already taken to try and solve the problem?
Logging in to mongodb with:
mongosh graylog
And issuing the command
db.sessions.drop()
Allows me to log in to graylog successfully, but only once. The next time anyone tries to log in the error is back. It is as if the login process works but somehow also corrupts the sessions collection, so next time a session cannot be loaded or created.
4. How can the community help?
By giving me further troubleshooting steps to try to pinpoint the issue? Upgrading to Graylog 5 / Opensearch / Mongodb 5 is not an option right now as it will require a bit of planning and some downtime - it really needs the issue fixing as it is, if possible. I don’t particularly want to throw time and effort at upgrading it right now to try and fix an issue which may be completely unrelated to version numbers.