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.