You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

260 lines
6.5 KiB

7 years ago
7 years ago
abci: Flush socket requests and responses immediately. (#6997) The main effect of this change is to flush the socket client and server message encoding buffers immediately once the message is fully and correctly encoded. This allows us to remove the timer and some other special cases, without changing the observed behaviour of the system. -- Background The socket protocol client and server each use a buffered writer to encode request and response messages onto the underlying connection. This reduces the possibility of a single message being split across multiple writes, but has the side-effect that a request may remain buffered for some time. The implementation worked around this by keeping a ticker that occasionally triggers a flush, and by flushing the writer in response to an explicit request baked into the client/server protocol (see also #6994). These workarounds are both unnecessary: Once a message has been dequeued for sending and fully encoded in wire format, there is no real use keeping all or part of it buffered locally. Moreover, using an asynchronous process to flush the buffer makes the round-trip performance of the request unpredictable. -- Benchmarks Code: https://play.golang.org/p/0ChUOxJOiHt I found no pre-existing performance benchmarks to justify the flush pattern, but a natural question is whether this will significantly harm client/server performance. To test this, I implemented a simple benchmark that transfers randomly-sized byte buffers from a no-op "client" to a no-op "server" over a Unix-domain socket, using a buffered writer, both with and without explicit flushes after each write. As the following data show, flushing every time (FLUSH=true) does reduce raw throughput, but not by a significant amount except for very small request sizes, where the transfer time is already trivial (1.9μs). Given that the client is calibrated for 1MiB transactions, the overhead is not meaningful. The percentage in each section is the speedup for flushing only when the buffer is full, relative to flushing every block. The benchmark uses the default buffer size (4096 bytes), which is the same value used by the socket client and server implementation: FLUSH NBLOCKS MAX AVG TOTAL ELAPSED TIME/BLOCK false 3957471 512 255 1011165416 2.00018873s 505ns true 1068568 512 255 273064368 2.000217051s 1.871µs (73%) false 536096 4096 2048 1098066401 2.000229108s 3.731µs true 477911 4096 2047 978746731 2.000177825s 4.185µs (10.8%) false 124595 16384 8181 1019340160 2.000235086s 16.053µs true 120995 16384 8179 989703064 2.000329349s 16.532µs (2.9%) false 2114 1048576 525693 1111316541 2.000479928s 946.3µs true 2083 1048576 526379 1096449173 2.001817137s 961.025µs (1.5%) Note also that the FLUSH=false baseline is actually faster than the production code, which flushes more often than is required by the buffer filling up. Moreover, the timer slows down the overall transaction rate of the client and server, indepenedent of how fast the socket transfer is, so the loss on a real workload is probably much less.
3 years ago
abci: Flush socket requests and responses immediately. (#6997) The main effect of this change is to flush the socket client and server message encoding buffers immediately once the message is fully and correctly encoded. This allows us to remove the timer and some other special cases, without changing the observed behaviour of the system. -- Background The socket protocol client and server each use a buffered writer to encode request and response messages onto the underlying connection. This reduces the possibility of a single message being split across multiple writes, but has the side-effect that a request may remain buffered for some time. The implementation worked around this by keeping a ticker that occasionally triggers a flush, and by flushing the writer in response to an explicit request baked into the client/server protocol (see also #6994). These workarounds are both unnecessary: Once a message has been dequeued for sending and fully encoded in wire format, there is no real use keeping all or part of it buffered locally. Moreover, using an asynchronous process to flush the buffer makes the round-trip performance of the request unpredictable. -- Benchmarks Code: https://play.golang.org/p/0ChUOxJOiHt I found no pre-existing performance benchmarks to justify the flush pattern, but a natural question is whether this will significantly harm client/server performance. To test this, I implemented a simple benchmark that transfers randomly-sized byte buffers from a no-op "client" to a no-op "server" over a Unix-domain socket, using a buffered writer, both with and without explicit flushes after each write. As the following data show, flushing every time (FLUSH=true) does reduce raw throughput, but not by a significant amount except for very small request sizes, where the transfer time is already trivial (1.9μs). Given that the client is calibrated for 1MiB transactions, the overhead is not meaningful. The percentage in each section is the speedup for flushing only when the buffer is full, relative to flushing every block. The benchmark uses the default buffer size (4096 bytes), which is the same value used by the socket client and server implementation: FLUSH NBLOCKS MAX AVG TOTAL ELAPSED TIME/BLOCK false 3957471 512 255 1011165416 2.00018873s 505ns true 1068568 512 255 273064368 2.000217051s 1.871µs (73%) false 536096 4096 2048 1098066401 2.000229108s 3.731µs true 477911 4096 2047 978746731 2.000177825s 4.185µs (10.8%) false 124595 16384 8181 1019340160 2.000235086s 16.053µs true 120995 16384 8179 989703064 2.000329349s 16.532µs (2.9%) false 2114 1048576 525693 1111316541 2.000479928s 946.3µs true 2083 1048576 526379 1096449173 2.001817137s 961.025µs (1.5%) Note also that the FLUSH=false baseline is actually faster than the production code, which flushes more often than is required by the buffer filling up. Moreover, the timer slows down the overall transaction rate of the client and server, indepenedent of how fast the socket transfer is, so the loss on a real workload is probably much less.
3 years ago
  1. package server
  2. import (
  3. "bufio"
  4. "context"
  5. "errors"
  6. "fmt"
  7. "io"
  8. "net"
  9. "runtime"
  10. "sync"
  11. "github.com/tendermint/tendermint/abci/types"
  12. "github.com/tendermint/tendermint/libs/log"
  13. tmnet "github.com/tendermint/tendermint/libs/net"
  14. "github.com/tendermint/tendermint/libs/service"
  15. )
  16. // var maxNumberConnections = 2
  17. type SocketServer struct {
  18. service.BaseService
  19. logger log.Logger
  20. proto string
  21. addr string
  22. listener net.Listener
  23. connsMtx sync.Mutex
  24. connsClose map[int]func()
  25. nextConnID int
  26. app types.Application
  27. }
  28. func NewSocketServer(logger log.Logger, protoAddr string, app types.Application) service.Service {
  29. proto, addr := tmnet.ProtocolAndAddress(protoAddr)
  30. s := &SocketServer{
  31. logger: logger,
  32. proto: proto,
  33. addr: addr,
  34. listener: nil,
  35. app: app,
  36. connsClose: make(map[int]func()),
  37. }
  38. s.BaseService = *service.NewBaseService(logger, "ABCIServer", s)
  39. return s
  40. }
  41. func (s *SocketServer) OnStart(ctx context.Context) error {
  42. ln, err := net.Listen(s.proto, s.addr)
  43. if err != nil {
  44. return err
  45. }
  46. s.listener = ln
  47. go s.acceptConnectionsRoutine(ctx)
  48. return nil
  49. }
  50. func (s *SocketServer) OnStop() {
  51. if err := s.listener.Close(); err != nil {
  52. s.logger.Error("error closing listener", "err", err)
  53. }
  54. s.connsMtx.Lock()
  55. defer s.connsMtx.Unlock()
  56. for _, closer := range s.connsClose {
  57. closer()
  58. }
  59. }
  60. func (s *SocketServer) addConn(closer func()) int {
  61. s.connsMtx.Lock()
  62. defer s.connsMtx.Unlock()
  63. connID := s.nextConnID
  64. s.nextConnID++
  65. s.connsClose[connID] = closer
  66. return connID
  67. }
  68. // deletes conn even if close errs
  69. func (s *SocketServer) rmConn(connID int) {
  70. s.connsMtx.Lock()
  71. defer s.connsMtx.Unlock()
  72. if closer, ok := s.connsClose[connID]; ok {
  73. closer()
  74. delete(s.connsClose, connID)
  75. }
  76. }
  77. func (s *SocketServer) acceptConnectionsRoutine(ctx context.Context) {
  78. for {
  79. if ctx.Err() != nil {
  80. return
  81. }
  82. // Accept a connection
  83. s.logger.Info("Waiting for new connection...")
  84. conn, err := s.listener.Accept()
  85. if err != nil {
  86. if !s.IsRunning() {
  87. return // Ignore error from listener closing.
  88. }
  89. s.logger.Error("Failed to accept connection", "err", err)
  90. continue
  91. }
  92. cctx, ccancel := context.WithCancel(ctx)
  93. connID := s.addConn(ccancel)
  94. s.logger.Info("Accepted a new connection", "id", connID)
  95. responses := make(chan *types.Response, 1000) // A channel to buffer responses
  96. once := &sync.Once{}
  97. closer := func(err error) {
  98. ccancel()
  99. once.Do(func() {
  100. if cerr := conn.Close(); err != nil {
  101. s.logger.Error("error closing connection",
  102. "id", connID,
  103. "close_err", cerr,
  104. "err", err)
  105. }
  106. s.rmConn(connID)
  107. switch {
  108. case errors.Is(err, context.Canceled):
  109. s.logger.Error("Connection terminated",
  110. "id", connID,
  111. "err", err)
  112. case errors.Is(err, context.DeadlineExceeded):
  113. s.logger.Error("Connection encountered timeout",
  114. "id", connID,
  115. "err", err)
  116. case errors.Is(err, io.EOF):
  117. s.logger.Error("Connection was closed by client",
  118. "id", connID)
  119. case err != nil:
  120. s.logger.Error("Connection error",
  121. "id", connID,
  122. "err", err)
  123. default:
  124. s.logger.Error("Connection was closed",
  125. "id", connID)
  126. }
  127. })
  128. }
  129. // Read requests from conn and deal with them
  130. go s.handleRequests(cctx, closer, conn, responses)
  131. // Pull responses from 'responses' and write them to conn.
  132. go s.handleResponses(cctx, closer, conn, responses)
  133. }
  134. }
  135. // Read requests from conn and deal with them
  136. func (s *SocketServer) handleRequests(
  137. ctx context.Context,
  138. closer func(error),
  139. conn io.Reader,
  140. responses chan<- *types.Response,
  141. ) {
  142. var bufReader = bufio.NewReader(conn)
  143. defer func() {
  144. // make sure to recover from any app-related panics to allow proper socket cleanup
  145. if r := recover(); r != nil {
  146. const size = 64 << 10
  147. buf := make([]byte, size)
  148. buf = buf[:runtime.Stack(buf, false)]
  149. closer(fmt.Errorf("recovered from panic: %v\n%s", r, buf))
  150. }
  151. }()
  152. for {
  153. req := &types.Request{}
  154. if err := types.ReadMessage(bufReader, req); err != nil {
  155. closer(fmt.Errorf("error reading message: %w", err))
  156. return
  157. }
  158. resp := s.processRequest(req)
  159. select {
  160. case <-ctx.Done():
  161. closer(ctx.Err())
  162. return
  163. case responses <- resp:
  164. }
  165. }
  166. }
  167. func (s *SocketServer) processRequest(req *types.Request) *types.Response {
  168. switch r := req.Value.(type) {
  169. case *types.Request_Echo:
  170. return types.ToResponseEcho(r.Echo.Message)
  171. case *types.Request_Flush:
  172. return types.ToResponseFlush()
  173. case *types.Request_Info:
  174. return types.ToResponseInfo(s.app.Info(*r.Info))
  175. case *types.Request_CheckTx:
  176. return types.ToResponseCheckTx(s.app.CheckTx(*r.CheckTx))
  177. case *types.Request_Commit:
  178. return types.ToResponseCommit(s.app.Commit())
  179. case *types.Request_Query:
  180. return types.ToResponseQuery(s.app.Query(*r.Query))
  181. case *types.Request_InitChain:
  182. return types.ToResponseInitChain(s.app.InitChain(*r.InitChain))
  183. case *types.Request_ListSnapshots:
  184. return types.ToResponseListSnapshots(s.app.ListSnapshots(*r.ListSnapshots))
  185. case *types.Request_OfferSnapshot:
  186. return types.ToResponseOfferSnapshot(s.app.OfferSnapshot(*r.OfferSnapshot))
  187. case *types.Request_PrepareProposal:
  188. return types.ToResponsePrepareProposal(s.app.PrepareProposal(*r.PrepareProposal))
  189. case *types.Request_ProcessProposal:
  190. return types.ToResponseProcessProposal(s.app.ProcessProposal(*r.ProcessProposal))
  191. case *types.Request_LoadSnapshotChunk:
  192. return types.ToResponseLoadSnapshotChunk(s.app.LoadSnapshotChunk(*r.LoadSnapshotChunk))
  193. case *types.Request_ApplySnapshotChunk:
  194. return types.ToResponseApplySnapshotChunk(s.app.ApplySnapshotChunk(*r.ApplySnapshotChunk))
  195. case *types.Request_ExtendVote:
  196. return types.ToResponseExtendVote(s.app.ExtendVote(*r.ExtendVote))
  197. case *types.Request_VerifyVoteExtension:
  198. return types.ToResponseVerifyVoteExtension(s.app.VerifyVoteExtension(*r.VerifyVoteExtension))
  199. case *types.Request_FinalizeBlock:
  200. return types.ToResponseFinalizeBlock(s.app.FinalizeBlock(*r.FinalizeBlock))
  201. default:
  202. return types.ToResponseException("Unknown request")
  203. }
  204. }
  205. // Pull responses from 'responses' and write them to conn.
  206. func (s *SocketServer) handleResponses(
  207. ctx context.Context,
  208. closer func(error),
  209. conn io.Writer,
  210. responses <-chan *types.Response,
  211. ) {
  212. bw := bufio.NewWriter(conn)
  213. for {
  214. select {
  215. case <-ctx.Done():
  216. closer(ctx.Err())
  217. return
  218. case res := <-responses:
  219. if err := types.WriteMessage(res, bw); err != nil {
  220. closer(fmt.Errorf("error writing message: %w", err))
  221. return
  222. }
  223. if err := bw.Flush(); err != nil {
  224. closer(fmt.Errorf("error writing message: %w", err))
  225. return
  226. }
  227. }
  228. }
  229. }