Not sure where to ask, maybe someone here can help. Very rarely, like once every few months, I see this exception:
heroku[web.1]: State changed from starting to up
app[web.1]: INFO aleph.http.server [aleph-server-pool-4] - Setting up insecure HTTP/1 server pipeline.
app[web.1]: INFO ring.logger [manifold-pool-2-1] - {:request-method :get, :uri "/ws/chet", :server-name "...", :ring.logger/type :starting}
app[web.1]: INFO ring.logger [manifold-pool-2-1] - {:request-method :get, :uri "/ws/chet", :server-name "...", :ring.logger/type :params, :params {"client-id" "..."}}
app[web.1]: INFO ring.logger [manifold-pool-2-1] - {:request-method :get, :uri "/ws/chet", :server-name "...", :ring.logger/type :finish, :status nil, :ring.logger/ms 61}
app[web.1]: INFO aleph.http.server [aleph-server-pool-1] - Setting up insecure HTTP/1 server pipeline.
app[web.1]: INFO ring.logger [manifold-pool-2-1] - {:request-method :get, :uri "/ws/chet", :server-name "...", :ring.logger/type :starting}
app[web.1]: INFO ring.logger [manifold-pool-2-1] - {:request-method :get, :uri "/ws/chet", :server-name "...", :ring.logger/type :params, :params {"client-id" "..."}}
heroku[router]: at=info method=GET path="/ws/chet?client-id=..." host=... request_id=... fwd="..." dyno=web.1 connect=0ms service=15ms status=101 bytes=129 protocol=https
app[web.1]: WARN io.netty.util.concurrent.DefaultPromise [aleph-server-pool-1] - An exception was thrown by io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker$1.operationComplete()
java.util.NoSuchElementException: http-server
at io.netty.channel.DefaultChannelPipeline.getContextOrDie(DefaultChannelPipeline.java:1073)
at io.netty.channel.DefaultChannelPipeline.remove(DefaultChannelPipeline.java:423)
at io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker$1.operationComplete(WebSocketServerHandshaker.java:235)
at io.netty.handler.codec.http.websocketx.WebSocketServerHandshaker$1.operationComplete(WebSocketServerHandshaker.java:230)
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590)
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:557)
at io.netty.util.concurrent.DefaultPromise.access$200(DefaultPromise.java:35)
at io.netty.util.concurrent.DefaultPromise$1.run(DefaultPromise.java:503)
at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:413)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at manifold.executor$thread_factory$reify__1884$f__1885.invoke(executor.clj:71)
at clojure.lang.AFn.run(AFn.java:22)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:1623)
And no complaints from any users, so no clue whether any requests are actually affected.
Does anyone have any clue what's going on?Is this (or could this be) during server shutdown?
That's why I included the first line. :) It's right after startup.
Not sure about any of the previous errors - didn't keep the logs.
There are no timestamps, this could as well be hours in a slacking env
It comes from the operationComplete callback, so the user-facing write has completed, and netty tried to remove the old http encoder from the pipeline, but it was apparently already gone. I can't really imagine how this exception looks from the client's perspective (if visible at all)
I removed the timestamps since they're way too wide. It all happened within 3 seconds from the first line. What you describe sounds like a potential race condition.
> I can't really imagine how this exception looks from the client's perspective (if visible at all) The fact that it's marked as a warning by Netty suggests that maybe users don't see it at all.