search

vapor / mysql-nio

🐬 Non-blocking, event-driven Swift client for MySQL.
MIT License
91 stars 26 forks source link

Unhandled packet assertion. Can this throw instead? #87

Closed JetForMe closed 1 year ago

JetForMe commented 1 year ago

Describe the bug

I've been working on a Vapor REST API project. I'm running locally on my Mac at home, and hitting a MySQL DB hosted at DigitalOcean. I came back to work on it after leaving it the night before to find the Vapor app stopped in Xcode at this assertion:

MySQLNIO/MySQLConnectionHandler.swift:89: Fatal error: unhandled packet: ByteBuffer { readerIndex: 0, writerIndex: 145, readableBytes: 145, capacity: 145, storageCapacity: 32768, slice: _ByteBufferSlice { 4..<149 }, storage: 0x000000010683f000 (32768 bytes) }
readable bytes (max 1k): [ ff bf 0f 23 48 59 30 30 30 54 68 65 20 63 6c 69 65 6e 74 20 77 61 73 20 64 69 73 63 6f 6e 6e 65 63 74 65 64 20 62 79 20 74 68 65 20 73 65 72 76 65 72 20 62 65 63 61 75 73 65 20 6f 66 20 69 6e 61 63 74 69 76 69 74 79 2e 20 53 65 65 20 77 61 69 74 5f 74 69 6d 65 6f 75 74 20 61 6e 64 20 69 6e 74 65 72 61 63 74 69 76 65 5f 74 69 6d 65 6f 75 74 20 66 6f 72 20 63 6f 6e 66 69 67 75 72 69 6e 67 20 74 68 69 73 20 62 65 68 61 76 69 6f 72 2e ]
2023-01-05 11:00:42.500355-0800 Run[10403:20023895] MySQLNIO/MySQLConnectionHandler.swift:89: Fatal error: unhandled packet: ByteBuffer { readerIndex: 0, writerIndex: 145, readableBytes: 145, capacity: 145, storageCapacity: 32768, slice: _ByteBufferSlice { 4..<149 }, storage: 0x000000010683f000 (32768 bytes) }
readable bytes (max 1k): [ ff bf 0f 23 48 59 30 30 30 54 68 65 20 63 6c 69 65 6e 74 20 77 61 73 20 64 69 73 63 6f 6e 6e 65 63 74 65 64 20 62 79 20 74 68 65 20 73 65 72 76 65 72 20 62 65 63 61 75 73 65 20 6f 66 20 69 6e 61 63 74 69 76 69 74 79 2e 20 53 65 65 20 77 61 69 74 5f 74 69 6d 65 6f 75 74 20 61 6e 64 20 69 6e 74 65 72 61 63 74 69 76 65 5f 74 69 6d 65 6f 75 74 20 66 6f 72 20 63 6f 6e 66 69 67 75 72 69 6e 67 20 74 68 69 73 20 62 65 68 61 76 69 6f 72 2e ]

I don't think there was an explicit query in progress, as it was just idling locally. The stack:

#4  0x00000001b86c5530 in assertionFailure(_:file:line:) ()
#5  0x0000000100f02058 in MySQLConnectionHandler.channelRead(context:data:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/mysql-nio/Sources/MySQLNIO/MySQLConnectionHandler.swift:89
#6  0x0000000100f0c25c in protocol witness for _ChannelInboundHandler.channelRead(context:data:) in conformance MySQLConnectionHandler ()
#7  0x0000000100191db8 in ChannelHandlerContext.invokeChannelRead(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1702
#8  0x0000000100191e14 in ChannelHandlerContext.invokeChannelRead(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1704
#9  0x000000010019679c in ChannelHandlerContext.fireChannelRead(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1515
#10 0x0000000100f3607c in MySQLPacketDecoder.decode(context:buffer:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/mysql-nio/Sources/MySQLNIO/Packet/MySQLPacketDecoder.swift:32
#11 0x0000000100f362c8 in protocol witness for ByteToMessageDecoder.decode(context:buffer:) in conformance MySQLPacketDecoder ()
#12 0x00000001001afa80 in closure #1 in ByteToMessageHandler.decodeLoop(context:decodeMode:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/Codec.swift:582
#13 0x00000001001b6914 in partial apply for closure #1 in ByteToMessageHandler.decodeLoop(context:decodeMode:) ()
#14 0x00000001001ae8e4 in ByteToMessageHandler.withNextBuffer(allowEmptyBuffer:_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/Codec.swift:539
#15 0x00000001001af3a4 in ByteToMessageHandler.decodeLoop(context:decodeMode:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/Codec.swift:578
#16 0x00000001001b0984 in ByteToMessageHandler.channelRead(context:data:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/Codec.swift:651
#17 0x00000001001b108c in protocol witness for _ChannelInboundHandler.channelRead(context:data:) in conformance ByteToMessageHandler<τ_0_0> ()
#18 0x0000000100191db8 in ChannelHandlerContext.invokeChannelRead(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1702
#19 0x000000010019679c in ChannelHandlerContext.fireChannelRead(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1515
#20 0x00000001009d6064 in NIOSSLHandler.doFlushReadData(context:receiveBuffer:readOnEmptyBuffer:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:517
#21 0x00000001009d1b08 in NIOSSLHandler.channelReadComplete(context:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio-ssl/Sources/NIOSSL/NIOSSLHandler.swift:190
#22 0x00000001009d76ec in protocol witness for _ChannelInboundHandler.channelReadComplete(context:) in conformance NIOSSLHandler ()
#23 0x0000000100191f2c in ChannelHandlerContext.invokeChannelReadComplete() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1712
#24 0x000000010018e96c in ChannelPipeline.fireChannelReadComplete0() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:903
#25 0x0000000100194358 in ChannelPipeline.SynchronousOperations.fireChannelReadComplete() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOCore/ChannelPipeline.swift:1170
#26 0x0000000100489b1c in BaseSocketChannel.readable0() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/BaseSocketChannel.swift:1143
#27 0x000000010048ab48 in BaseSocketChannel.readable() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/BaseSocketChannel.swift:1070
#28 0x000000010048ba94 in protocol witness for SelectableChannel.readable() in conformance BaseSocketChannel<τ_0_0> ()
#29 0x00000001004f64b0 in SelectableEventLoop.handleEvent<τ_0_0>(_:channel:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:413
#30 0x00000001004f7948 in closure #2 in closure #2 in SelectableEventLoop.run() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:488
#31 0x00000001004fbe38 in partial apply for closure #2 in closure #2 in SelectableEventLoop.run() ()
#32 0x0000000100509ba0 in Selector.whenReady0(strategy:onLoopBegin:_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectorKqueue.swift:258
#33 0x00000001005028c8 in Selector.whenReady(strategy:onLoopBegin:_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectorGeneric.swift:288
#34 0x00000001004f7640 in closure #2 in SelectableEventLoop.run() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:480
#35 0x00000001004fac20 in partial apply for closure #2 in SelectableEventLoop.run() ()
#36 0x00000001004f18bc in closure #1 in withAutoReleasePool<τ_0_0>(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:26
#37 0x00000001004f1920 in partial apply for closure #1 in withAutoReleasePool<τ_0_0>(_:) ()
#38 0x00000001bffa7474 in autoreleasepool<τ_0_0>(invoking:) ()
#39 0x00000001004f1850 in withAutoReleasePool<τ_0_0>(_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:25
#40 0x00000001004f6864 in SelectableEventLoop.run() at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/SelectableEventLoop.swift:479
#41 0x00000001004bd41c in static MultiThreadedEventLoopGroup.runTheLoop(thread:parentGroup:canEventLoopBeShutdownIndividually:selectorFactory:initializer:_:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:95
#42 0x00000001004bd99c in closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/MultiThreadedEventLoopGroup.swift:116
#43 0x00000001004c3364 in partial apply for closure #1 in static MultiThreadedEventLoopGroup.setupThreadAndEventLoop(name:parentGroup:selectorFactory:initializer:) ()
#44 0x0000000100529dc4 in thunk for @escaping @callee_guaranteed (@guaranteed NIOThread) -> () ()
#45 0x000000010052de48 in closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) at /Users/rmann/Library/Developer/Xcode/DerivedData/camsync-bylosnkysgfpvnbwbikdmasqdlgw/SourcePackages/checkouts/swift-nio/Sources/NIOPosix/ThreadPosix.swift:105
#46 0x000000010052df04 in @objc closure #1 in static ThreadOpsPosix.run(handle:args:detachThread:) ()
#47 0x000000010396d5d4 in _pthread_start ()

The queue has 16 nil entries:

(lldb) po self.queue
▿ [ _ _ _ _ _ _ _ _ _ _ _ _ _ _ <_ _ ] (bufferCapacity: 16, ringLength: 0)
  ▿ _buffer : 16 elements
    - 0 : nil
    - 1 : nil
    - 2 : nil
    - 3 : nil
    - 4 : nil
    - 5 : nil
    - 6 : nil
    - 7 : nil
    - 8 : nil
    - 9 : nil
    - 10 : nil
    - 11 : nil
    - 12 : nil
    - 13 : nil
    - 14 : nil
    - 15 : nil
  - headBackingIndex : 14
  - tailBackingIndex : 14
(lldb) po data
▿ NIOAny { [255, 191, 15, 35, 72, 89, 48, 48, 48, 84, 104, 101, 32, 99, 108, 105]... (err: true, ok: false, eof: false) }
  ▿ _storage : _NIOAny
    ▿ other : [255, 191, 15, 35, 72, 89, 48, 48, 48, 84, 104, 101, 32, 99, 108, 105]... (err: true, ok: false, eof: false)
      ▿ payload : ByteBuffer { readerIndex: 0, writerIndex: 145, readableBytes: 145, capacity: 145, storageCapacity: 32768, slice: _ByteBufferSlice { 4..<149 }, storage: 0x000000010683f000 (32768 bytes) }
        ▿ _storage : <_Storage: 0x600001718180>
        - _readerIndex : 0
        - _writerIndex : 145
        ▿ _slice : _ByteBufferSlice { 4..<149 }
          - upperBound : 149
          ▿ _begin : 4
            ▿ _backing : 2 elements
              - .0 : 0
              - .1 : 4

To Reproduce

I didn't try to reproduce it.

Expected behavior

Ideally an error like this wouldn't crash the process. Maybe roll back the current transaction and throw an error?

Environment

$ vapor --version
framework: 4.67.5
toolbox: 18.6.0

Ventura 13.1 (22C65) mysql-nio v1.4.0 mysql-kit v4.6.1 MySQL server v8.0.28, protocol version 10

Additional context

Add any other context about the problem here.

gwynne commented 1 year ago

The packet that was unhandled is an ERR_Packet; the error message is The client was disconnected by the server because of inactivity. See wait_timeout and interactive_timeout for configuring this behavior..

This crash is a known bug in the packet handling logic, and has been addressed in the upcoming major revamp of MySQLNIO, as have all the other fatal errors, assertion failures, and other unnecessary crashes on failure.

JetForMe commented 1 year ago

Woo hoo!