Use logger

This commit is contained in:
Xiaoguang Sun 2022-01-16 23:18:03 +08:00
parent 6fc0bcbb10
commit 3ea3c76ce9
1 changed files with 16 additions and 29 deletions

View File

@ -51,7 +51,6 @@ import java.nio.channels.SocketChannel;
import java.nio.channels.spi.SelectorProvider; import java.nio.channels.spi.SelectorProvider;
import java.util.Map; import java.util.Map;
import java.util.concurrent.Executor; import java.util.concurrent.Executor;
import sun.nio.ch.ChannelPerf;
/** {@link io.netty.channel.socket.SocketChannel} which uses NIO selector based implementation. */ /** {@link io.netty.channel.socket.SocketChannel} which uses NIO selector based implementation. */
public class NioSocketChannel extends AbstractNioByteChannel public class NioSocketChannel extends AbstractNioByteChannel
@ -394,18 +393,12 @@ public class NioSocketChannel extends AbstractNioByteChannel
allocHandle.attemptedBytesRead(attemptedBytes); allocHandle.attemptedBytesRead(attemptedBytes);
Histogram.Timer socketReadTime = socketReadDuration.startTimer(); Histogram.Timer socketReadTime = socketReadDuration.startTimer();
SocketChannel sc = javaChannel(); SocketChannel sc = javaChannel();
long start = System.currentTimeMillis();
int localReadBytes = byteBuf.writeBytes(sc, allocHandle.attemptedBytesRead()); int localReadBytes = byteBuf.writeBytes(sc, allocHandle.attemptedBytesRead());
double duration = socketReadTime.observeDuration(); double duration = socketReadTime.observeDuration();
if (duration > SLOW_IO_THRESHOLD) { if (duration > SLOW_IO_THRESHOLD) {
// read slower than 10ms is strange // read slower than 10ms is strange
System.out.println( logger.warn("[slow io] read {} bytes at {} took {} ms", localReadBytes, start, duration);
"[slow io] read "
+ localReadBytes
+ " bytes at "
+ HistogramUtils.getHistogramTimerStart(socketReadTime)
+ " took "
+ duration
+ " ms");
} }
socketReadBytes.observe(localReadBytes); socketReadBytes.observe(localReadBytes);
socketReadLeftBytes.observe(attemptedBytes - localReadBytes); socketReadLeftBytes.observe(attemptedBytes - localReadBytes);
@ -476,20 +469,17 @@ public class NioSocketChannel extends AbstractNioByteChannel
int attemptedBytes = buffer.remaining(); int attemptedBytes = buffer.remaining();
socketWriteBytes.observe(attemptedBytes); socketWriteBytes.observe(attemptedBytes);
Histogram.Timer writeTime = socketWriteDuration.startTimer(); Histogram.Timer writeTime = socketWriteDuration.startTimer();
long start = System.currentTimeMillis();
final int localWrittenBytes = ch.write(buffer); final int localWrittenBytes = ch.write(buffer);
double duration = writeTime.observeDuration(); double duration = writeTime.observeDuration();
if (duration > SLOW_IO_THRESHOLD) { if (duration > SLOW_IO_THRESHOLD) {
// read slower than 10ms is strange // read slower than 10ms is strange
System.out.println( logger.warn(
"[slow io] write " "[slow io] write {}/{} bytes at {} took {} ms",
+ attemptedBytes attemptedBytes,
+ "/" localWrittenBytes,
+ localWrittenBytes start,
+ " bytes at " duration);
+ HistogramUtils.getHistogramTimerStart(writeTime)
+ " took "
+ duration
+ "ms");
} }
socketWrittenBytes.observe(localWrittenBytes); socketWrittenBytes.observe(localWrittenBytes);
if (localWrittenBytes <= 0) { if (localWrittenBytes <= 0) {
@ -512,20 +502,17 @@ public class NioSocketChannel extends AbstractNioByteChannel
long attemptedBytes = in.nioBufferSize(); long attemptedBytes = in.nioBufferSize();
socketWriteBytes.observe(attemptedBytes); socketWriteBytes.observe(attemptedBytes);
Histogram.Timer writeTime = socketWriteDuration.startTimer(); Histogram.Timer writeTime = socketWriteDuration.startTimer();
long start = System.currentTimeMillis();
final long localWrittenBytes = ch.write(nioBuffers, 0, nioBufferCnt); final long localWrittenBytes = ch.write(nioBuffers, 0, nioBufferCnt);
double duration = writeTime.observeDuration(); double duration = writeTime.observeDuration();
if (duration > SLOW_IO_THRESHOLD) { if (duration > SLOW_IO_THRESHOLD) {
// read slower than 10ms is strange // read slower than 10ms is strange
System.out.println( logger.warn(
"[slow io] write " "[slow io] write {}/{} bytes at {} took {} ms",
+ attemptedBytes attemptedBytes,
+ "/" localWrittenBytes,
+ localWrittenBytes start,
+ " bytes at " duration);
+ HistogramUtils.getHistogramTimerStart(writeTime)
+ " took "
+ duration
+ "ms");
} }
socketWrittenBytes.observe(localWrittenBytes); socketWrittenBytes.observe(localWrittenBytes);
if (localWrittenBytes <= 0) { if (localWrittenBytes <= 0) {