Clojurians Log v2
aleph 2024-01-24
I see a lot of these logs with aleph 0.7 that I didn't see before with 0.6:
2024-01-24 09:52:39.713 [prod_02] [WARN] aleph.http.client exception-handler #error {
:cause Connection reset
:via
[{:type java.net.SocketException
:message Connection reset
:at [sun.nio.ch.SocketChannelImpl throwConnectionReset nil -1]}]
:trace
[[sun.nio.ch.SocketChannelImpl throwConnectionReset nil -1]
[sun.nio.ch.SocketChannelImpl read nil -1]
[io.netty.buffer.PooledByteBuf setBytes PooledByteBuf.java 254]
[io.netty.buffer.AbstractByteBuf writeBytes AbstractByteBuf.java 1132]
[io.netty.channel.socket.nio.NioSocketChannel doReadBytes NioSocketChannel.java 357]
[io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe read AbstractNioByteChannel.java 151]
[io.netty.channel.nio.NioEventLoop processSelectedKey NioEventLoop.java 788]
[io.netty.channel.nio.NioEventLoop processSelectedKeysOptimized NioEventLoop.java 724]
[io.netty.channel.nio.NioEventLoop processSelectedKeys NioEventLoop.java 650]
[io.netty.channel.nio.NioEventLoop run NioEventLoop.java 562]
[io.netty.util.concurrent.SingleThreadEventExecutor$4 run SingleThreadEventExecutor.java 997]
[io.netty.util.internal.ThreadExecutorMap$2 run ThreadExecutorMap.java 74]
[manifold.executor$thread_factory$reify__33943$f__33944 invoke executor.clj 71]
[clojure.lang.AFn run AFn.java 22]
[io.netty.util.concurrent.FastThreadLocalRunnable run FastThreadLocalRunnable.java 30]
[java.lang.Thread run nil -1]]}
2024-01-24 09:53:34.276 [prod_02] [INFO] aleph.netty SSL handshake completed
2024-01-24 09:53:34.308 [prod_02] [INFO] aleph.netty SSL handshake completed
2024-01-24 09:55:39.592 [prod_02] [WARN] aleph.http.client exception-handler #error {
Yeah, we could change the SSL handshake to debug level. It's not that interesting. The "Connection reset" SocketException could be from a normal peer-initiated reset, it could be a timeout, etc. Whether it's of concern depends on the application and the network behavior, which is why it's only a warning. In general, older Aleph lacked a lot of logging, so people should expect to see more information with 0.7.0+.
@vale can you give me some more details? I’m not sure what you mean here.
Making a http request using aleph, a bunch of debug log lines are emitted. The "logger" is identified as aleph.http.common, aleph.http.core, aleph.http.client, and some are aleph-client. The dot-separated ones, I can filter as one in logback.xml with logger="aleph", but aleph-client slips through
Ahh, those are logs emitted by Netty's LoggingHandler on Aleph's behalf. Depending on what you're trying to do, you could bump up the logging level by setting :log-activity :warning or :log-activity :info, etc. You can try applying filters on the Netty namespaces, either io.netty.handler.logging or whatever class the InternalLogger is. Can also pass :log-activity nil to disable it.
I was not aware of that setting, let me try
Could the aleph-client logger be unified into aleph.http.client? Currently it has to be specified separately in logback.xml and is not caught by logger name="aleph"
Well that's the thing, I've already set all the netty and aleph namespaced loggers to warn, but aleph-client still goes through
Including setting :log-activity :warning?
But wouldn’t setting the log level for that namespace suppress other maybe more important warnings?
Yes, which is why I downgraded the log level for the handshake in 0.7.1
Ye thanks for that. I was talking about the connection reset here
Ahh. I think that should be left as a warning for now. It's really hard to know how a user wants to interpret it. It's true connection resets are just a fact of life, though, so if people find it's just useless noise, I can downgrade it to info. But generally, that should be left up to them. If you're using log4j, RegexFilters in the config can remove those particular lines. I assume other logging platforms have similar capabilities.