Kitura/Kitura-Sample

Hello page crashed

Closed this issue · 5 comments

Hi,

App crashed for unknown reason upon visiting /hello, see log below. Could'n reproduce it.
OS: sierra, browser: Safari 10.

UPDATE invoking /hello and / pages after each other might result in crash. Perhaps they interfere each other in a way (code is not thread safe?).

almacska:Kitura-Sample segabor$ ./.build/debug/KituraSample
 VERBOSE: run() Kitura.swift line 71 - Starting Kitura framework... 
 VERBOSE: run() Kitura.swift line 73 - Starting an HTTP Server on port 8090... 
 INFO: listen(socket:port:) HTTPServer.swift line 128 - Listening on port 8090 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:52500 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
fatal error: Index out of range
Current stack trace:
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:52503 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:52504 
0    libswiftCore.dylib                 0x00000001023fb580 swift_reportError + 132
1    libswiftCore.dylib                 0x0000000102418850 _swift_stdlib_reportFatalError + 61
2    libswiftCore.dylib                 0x0000000102214550 specialized specialized StaticString.withUTF8Buffer<A> ((UnsafeBufferPointer<UInt8>) -> A) -> A + 355
3    libswiftCore.dylib                 0x000000010238c600 partial apply for (_fatalErrorMessage(StaticString, StaticString, StaticString, UInt, flags : UInt32) -> Never).(closure #2) + 109
4    libswiftCore.dylib                 0x0000000102214550 specialized specialized StaticString.withUTF8Buffer<A> ((UnsafeBufferPointer<UInt8>) -> A) -> A + 355
5    libswiftCore.dylib                 0x0000000102347970 specialized _fatalErrorMessage(StaticString, StaticString, StaticString, UInt, flags : UInt32) -> Never + 96
6    libswiftCore.dylib                 0x00000001021fc830 _ArrayBuffer._checkInoutAndNativeTypeCheckedBounds(Int, wasNativeTypeChecked : Bool) -> () + 300
7    libswiftCore.dylib                 0x000000010220d510 Array.subscript.getter + 103
8    KituraSample                       0x0000000101db2730 IncomingSocketHandler.socketReaderQueue(fd : Int32) -> DispatchQueue + 159
9    KituraSample                       0x0000000101db3940 IncomingSocketHandler.handleBufferedReadData() -> () + 86
10   KituraSample                       0x0000000101dd9800 IncomingHTTPSocketProcessor.keepAlive() -> () + 260
11   KituraSample                       0x0000000101dd5c10 HTTPServerResponse.end() throws -> () + 164
12   KituraSample                       0x0000000101dd8490 protocol witness for ServerResponse.end() throws -> () in conformance HTTPServerResponse + 55
13   KituraSample                       0x0000000101e42530 RouterResponse.end() throws -> () + 2007
14   KituraSample                       0x0000000101e14c90 FileResourceServer.sendIfFound(resource : String, usingResponse : RouterResponse) -> () + 419
15   KituraSample                       0x0000000101e24a80 Router.process(request : RouterRequest, response : RouterResponse, callback : () -> ()) -> () + 1294
16   KituraSample                       0x0000000101e25410 Router.handle(request : ServerRequest, response : ServerResponse) -> () + 339
17   KituraSample                       0x0000000101e26220 protocol witness for ServerDelegate.handle(request : ServerRequest, response : ServerResponse) -> () in conformance Router + 64
18   KituraSample                       0x0000000101dd9650 IncomingHTTPSocketProcessor.(parsingComplete() -> ()).(closure #1) + 372
19   KituraSample                       0x0000000101db3090 thunk + 39
20   libdispatch.dylib                  0x00007fff9d9d0f53 _dispatch_call_block_and_release + 12
21   libdispatch.dylib                  0x00007fff9d9c8120 _dispatch_client_callout + 8
22   libdispatch.dylib                  0x00007fff9d9c9d04 _dispatch_root_queue_drain + 917
23   libdispatch.dylib                  0x00007fff9d9c9c54 _dispatch_worker_thread3 + 99
24   libsystem_pthread.dylib            0x00007fff9dc14233 _pthread_wqthread + 1299
25   libsystem_pthread.dylib            0x00007fff9dc14214 start_wqthread + 13
Illegal instruction: 4

Another log

almacska:Kitura-Sample segabor$ ./.build/debug/KituraSample
 VERBOSE: run() Kitura.swift line 71 - Starting Kitura framework... 
 VERBOSE: run() Kitura.swift line 73 - Starting an HTTP Server on port 8090... 
 INFO: listen(socket:port:) HTTPServer.swift line 128 - Listening on port 8090 




 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53102 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 ERROR: handleRead() IncomingSocketHandler.swift line 110 - Error code: -9983, Connection reset by peer 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53110 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53111 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53112 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53113 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53114 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53115 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53117 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 ERROR: write(from:length:) IncomingSocketHandler.swift line 262 - Write to socket (file descriptor 10 failed. Error number=32. Message=Broken pipe. 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53119 
 ERROR: handleRead() IncomingSocketHandler.swift line 110 - Error code: -9983, Connection reset by peer 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53125 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53126 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53127 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53128 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53129 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53197 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53200 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53201 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53202 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53203 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53204 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53205 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53206 
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53207 
 INFO: handle(request:response:next:) main.swift line 45 - Authorization: nil 
fatal error: Index out of range
Current stack trace:
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53208 
0    libswiftCore.dylib                 0x000000010bc20580 swift_reportError + 132
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53209 
1    libswiftCore.dylib                 0x000000010bc3d850 _swift_stdlib_reportFatalError + 61
2    libswiftCore.dylib                 0x000000010ba39550 specialized specialized StaticString.withUTF8Buffer<A> ((UnsafeBufferPointer<UInt8>) -> A) -> A + 355
3    libswiftCore.dylib                 0x000000010bbb1600 partial apply for (_fatalErrorMessage(StaticString, StaticString, StaticString, UInt, flags : UInt32) -> Never).(closure #2) + 109
4    libswiftCore.dylib                 0x000000010ba39550 specialized specialized StaticString.withUTF8Buffer<A> ((UnsafeBufferPointer<UInt8>) -> A) -> A + 355
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53210 
5    libswiftCore.dylib                 0x000000010bb6c970 specialized _fatalErrorMessage(StaticString, StaticString, StaticString, UInt, flags : UInt32) -> Never + 96
 INFO: listen(socket:port:) HTTPServer.swift line 133 - Accepted connection from: 127.0.0.1:53211 
6    libswiftCore.dylib                 0x000000010ba21830 _ArrayBuffer._checkInoutAndNativeTypeCheckedBounds(Int, wasNativeTypeChecked : Bool) -> () + 300
7    libswiftCore.dylib                 0x000000010ba32510 Array.subscript.getter + 103
8    KituraSample                       0x000000010b5d7730 IncomingSocketHandler.socketReaderQueue(fd : Int32) -> DispatchQueue + 159
9    KituraSample                       0x000000010b5d8940 IncomingSocketHandler.handleBufferedReadData() -> () + 86
10   KituraSample                       0x000000010b5fe800 IncomingHTTPSocketProcessor.keepAlive() -> () + 260
11   KituraSample                       0x000000010b5fac10 HTTPServerResponse.end() throws -> () + 164
12   KituraSample                       0x000000010b5fd490 protocol witness for ServerResponse.end() throws -> () in conformance HTTPServerResponse + 55
13   KituraSample                       0x000000010b667530 RouterResponse.end() throws -> () + 2007
14   KituraSample                       0x000000010b639c90 FileResourceServer.sendIfFound(resource : String, usingResponse : RouterResponse) -> () + 419
15   KituraSample                       0x000000010b649a80 Router.process(request : RouterRequest, response : RouterResponse, callback : () -> ()) -> () + 1294
16   KituraSample                       0x000000010b64a410 Router.handle(request : ServerRequest, response : ServerResponse) -> () + 339
17   KituraSample                       0x000000010b64b220 protocol witness for ServerDelegate.handle(request : ServerRequest, response : ServerResponse) -> () in conformance Router + 64
18   KituraSample                       0x000000010b5fe650 IncomingHTTPSocketProcessor.(parsingComplete() -> ()).(closure #1) + 372
19   KituraSample                       0x000000010b5d8090 thunk + 39
20   libdispatch.dylib                  0x00007fff9d9d0f53 _dispatch_call_block_and_release + 12
21   libdispatch.dylib                  0x00007fff9d9c8120 _dispatch_client_callout + 8
22   libdispatch.dylib                  0x00007fff9d9c9d04 _dispatch_root_queue_drain + 917
23   libdispatch.dylib                  0x00007fff9d9c9c54 _dispatch_worker_thread3 + 99
24   libsystem_pthread.dylib            0x00007fff9dc14233 _pthread_wqthread + 1299
25   libsystem_pthread.dylib            0x00007fff9dc14214 start_wqthread + 13
Illegal instruction: 4

I was thinking on other ways to reproduce the issue, maybe a simple stress test could make it crash again. Indeed, it succeeded with wrk

almacska:Kitura-Sample segabor$ wrk -c 10 -d 2s http://localhost:8090/hello
Running 2s test @ http://localhost:8090/hello
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     9.36ms    3.64ms  27.44ms   73.12%
    Req/Sec   535.45    136.21     0.89k    87.50%
  2139 requests in 2.01s, 412.68KB read
Requests/sec:   1065.62
Transfer/sec:    205.59KB

Almost all executions ended up app exiting with 'fatal error: Index out of range' error.

Taking a closer look into the issue revealed that IncomingSocketHandler.socketReaderQueue selector is being invoked with invalid socket. Int this case socket.socketfd is -1.
So expression below evaluates to -1 causing index out of bounds error

IncomingSocketHandler.socketReaderQueues[Int(fd) % numberOfSocketReaderQueues]

Most probably that faulty socket is the one that responded to the last client request. So I think it is related to socket close.

Thank you for the detailed diagnostics. We'll fix the issue shortly.

Kitura issue Kitura/Kitura#784 has been opened to deal with this problem. The Kitura-net branch issue_784 has what I think is a fix for this problem. Hopefully we will merge it on Wednesday.

The patch you provided works well, thanks. I'm going to close the ticket.