- 6.1 About Ethernet
- 6.2 About Hubs, Switches, and Routers
- 6.3 About TCP/IP
- 6.4 About Packets
- 6.5 About Remote Procedure Calls (RPCs)
- 6.6 Slop
- 6.7 Observing Network Traffic
- 6.8 Sample RPC Message Definition
- 6.9 Sample Logging Design
- 6.10 Sample Client-Server System Using RPCs
- 6.11 Sample Server Program
- 6.12 Spinlocks
- 6.13 Sample Client Program
- 6.14 Measuring One Sample Client-Server RPC
- 6.15 Postprocessing RPC Logs
- 6.16 Observations
- 6.17 Summary
- Exercises
This chapter is from the book
This chapter is from the book
This chapter is from the book
6.16 Observations
On a sample server pair of machines, I measured 9.972 msec to send the Write() request from client to server, 1.118 msec to process it on the server, and 10 usec to send the response back to the client. My estimates of the first and last times were pretty reasonable, but my processing time estimate was 10x too low (see Table 6.1).
Table 6.1 Estimated RPC Elapsed Time vs. Measured Action Estimate Actual Send 1MB request 10 msec 9.972 msec
Action |
Estimate |
Actual |
|---|---|---|
Send 1MB request |
10 msec |
9.972 msec |
Process request |
100 usec |
1118 usec |
Send 100 byte response |
2 usec |
10 usec |
Based on the client-side log, Figure 6.17 shows 10 such RPCs lined up on time across about 120 msec, using the style of Figure 6.8. The hollow part of the lines (more precisely, the white overlaid lines) show approximately the message transmission time for the 1MB client => server messages. Among other things, you can see the 1–2 msec gap on the client from the end of one RPC to the beginning of the next one (oval around the first gap).
){kind=link}
)
Figure 6.17 Ten RPCs, each sending 1MB of data. The oval highlights the 1–2 msec gap between successive RPCs.
Figure 6.18 shows the same 10 RPCs, but this time they are aligned to a common starting point, so the relative times of the different RPCs are easily compared. Now it is clearer that the first few RPCs take longer, and then the timing settles down a bit. It is also clearer that number seven has an extra delay in getting its response message back to the client.
)
Figure 6.18 The same 10 RPCs, but this time all with the same start time of zero
The request time from client to server is about 9 msec, as we estimated, but the time processing on the server is about 1 msec, longer than the 100 usec per 1MB that we estimated. Why was our estimate off?
Copying each 1MB message from network card to kernel buffer, then kernel buffer to user buffer, then user buffer to separate key and value strings, and then value string to map entry, each one MB in our sample server code is read or written to memory about eight times, not just once. This boosts our estimate to about 800 usec for all those copies, close to the observed 1 msec. To complete the picture, the response time from server to client is about 350 usec, a little longer than I would have expected but not terrible. Estimating ahead of time makes it easy to spot discrepancies.