search

xitrum-framework / xitrum

Async and clustered Scala web framework and HTTP(S) server
http://xitrum-framework.github.io/
MIT License
446 stars 52 forks source link

Invalid range request causes increase in CPU usage as 100% #675

Closed georgeOsdDev closed 5 years ago

georgeOsdDev commented 5 years ago

Xitrum version: 3.28.15

Reproduce step: Create public file request with invalid(bigger than real file size) range header.

$ git clone https://github.com/xitrum-framework/xitrum-new
$ cd xitrum-new/
$ dd if=/dev/urandom bs=1024 count=1024 > public/dummy.jpg
$ sbt/sbt fgRun
$ curl 'http://localhost:8000/dummy.jpg' -H 'Range: bytes=0-2000000' > /dev/null

https://github.com/xitrum-framework/xitrum/blob/master/src/main/scala/xitrum/handler/outbound/XSendFile.scala#L180 operationComplete on this line will never called because DefaultFileRegion.transferTo never end.

thread dump

"nioEventLoopGroup-3-1" #322 prio=10 os_prio=0 tid=0x00007fc23801f800 nid=0x515 runnable [0x00007fc25e8b5000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.FileDispatcherImpl.size0(Native Method)
        at sun.nio.ch.FileDispatcherImpl.size(FileDispatcherImpl.java:84)
        at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:309)
        - locked <0x000000077f34f240> (a java.lang.Object)
        at sun.nio.ch.FileChannelImpl.transferTo(FileChannelImpl.java:565)
        at io.netty.channel.DefaultFileRegion.transferTo(DefaultFileRegion.java:145)
        at io.netty.channel.socket.nio.NioSocketChannel.doWriteFileRegion(NioSocketChannel.java:357)
        at io.netty.channel.nio.AbstractNioByteChannel.doWriteInternal(AbstractNioByteChannel.java:235)
        at io.netty.channel.nio.AbstractNioByteChannel.doWrite0(AbstractNioByteChannel.java:209)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:395)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:367)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:640)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:581)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:498)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:460)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:745)

"nioEventLoopGroup-3-1" #322 prio=10 os_prio=0 tid=0x00007fc23801f800 nid=0x515 runnable [0x00007fc25e8b5000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x000000078263dba0> (a io.netty.channel.nio.SelectedSelectionKeySet)
        - locked <0x00000007826403d8> (a java.util.Collections$UnmodifiableSet)
        - locked <0x000000078263ebc8> (a sun.nio.ch.EPollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62)
        at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:755)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:410)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:745)

"nioEventLoopGroup-3-1" #322 prio=10 os_prio=0 tid=0x00007fc23801f800 nid=0x515 runnable [0x00007fc25e8b5000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.NativeThread.current(Native Method)
        at sun.nio.ch.NativeThreadSet.add(NativeThreadSet.java:46)
        at sun.nio.ch.FileChannelImpl.transferToDirectly(FileChannelImpl.java:439)
        at sun.nio.ch.FileChannelImpl.transferTo(FileChannelImpl.java:575)
        at io.netty.channel.DefaultFileRegion.transferTo(DefaultFileRegion.java:145)
        at io.netty.channel.socket.nio.NioSocketChannel.doWriteFileRegion(NioSocketChannel.java:357)
        at io.netty.channel.nio.AbstractNioByteChannel.doWriteInternal(AbstractNioByteChannel.java:235)
        at io.netty.channel.nio.AbstractNioByteChannel.doWrite0(AbstractNioByteChannel.java:209)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:395)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:367)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:640)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:581)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:498)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:460)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:745)

"nioEventLoopGroup-3-1" #322 prio=10 os_prio=0 tid=0x00007fc23801f800 nid=0x515 runnable [0x00007fc25e8b5000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.FileChannelImpl.transferTo0(Native Method)
        at sun.nio.ch.FileChannelImpl.transferToDirectly(FileChannelImpl.java:443)
        at sun.nio.ch.FileChannelImpl.transferTo(FileChannelImpl.java:575)
        at io.netty.channel.DefaultFileRegion.transferTo(DefaultFileRegion.java:145)
        at io.netty.channel.socket.nio.NioSocketChannel.doWriteFileRegion(NioSocketChannel.java:357)
        at io.netty.channel.nio.AbstractNioByteChannel.doWriteInternal(AbstractNioByteChannel.java:235)
        at io.netty.channel.nio.AbstractNioByteChannel.doWrite0(AbstractNioByteChannel.java:209)
        at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:395)
        at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934)
        at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.forceFlush(AbstractNioChannel.java:367)
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:640)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:581)
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:498)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:460)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:745)

https://github.com/xitrum-framework/xitrum/blob/master/src/main/scala/xitrum/handler/outbound/XSendFile.scala#L141 This line should be like below?

val endIndex2 = if (endIndex >= 0) Math.min(endIndex, raf.length - 1) else raf.length - 1
ngocdaothanh commented 5 years ago

Thanks for reporting this serious bug!

val endIndex2 = if (endIndex >= 0) Math.min(endIndex, raf.length - 1) else raf.length - 1

I think we should also check startIndex. Can you create a pull request?

georgeOsdDev commented 5 years ago

I created PR #676. This PR also add 416 REQUESTED RANGE NOT SATISFIABLE for invalid startIndex.

Referenced: https://github.com/playframework/playframework/blob/8793cfaa568f79e822cb11c1d6a156331ca9ba74/framework/src/play/src/main/scala/play/api/mvc/RangeResult.scala

georgeOsdDev commented 5 years ago

DefaultFileRegion.transferTo never end

Essentially it seems to be a matter of Netty(or sun.nio.ch.FileChannelImpl?). So CPU usage increase bug is potentially left.

ngocdaothanh commented 5 years ago

Thanks, I've merged the PR. I'll release a new version very soon.

Maybe I'll improve the code a little bit (adding test).

Essentially it seems to be a matter of Netty(or sun.nio.ch.FileChannelImpl?).

Yes, it's a potential risk. Maybe Netty can do a check, before calling sun.nio.ch.FileChannelImpl.transferTo.

georgeOsdDev commented 5 years ago

Thanks 🙏 🙏 🙏

ngocdaothanh commented 5 years ago

I'll release a new version very soon.

I've just released version 3.28.16: https://groups.google.com/forum/#!topic/xitrum-framework/DVBHlfxtywc

Thanks for reporting and fixing.

georgeOsdDev commented 5 years ago

Netty team fixed at 4.1.34.Final netty/netty#8868 netty/netty#8885