Back to the Table of contents

Part 1: Java RMI timing

The following aspects of the performance of the Java RMI implementation have been measured:

• the cost of getting a network object via the  Naming.lookup(...)  method call (table/graph: Remote Objects Timing, reference: lookup);
• the cost of creating a new object implementing an interface which extends  java.rmi.Remote  (table/graph: Remote Objects Timing, reference: create);
• the cost of binding a network object in the registry via the  Naming.rebind(...)  method call (table/graph: Remote Objects timing, reference: bind);
• the cost of a remote method invocation:
  • with no arguments (table/graph: Remote Objects Timing, reference: nothing),
  • with a locally created network object passed as an argument (table/graph: Remote Objects Timing, reference: local),
  • with a network object received from the remote machine passed as an argument (table/graph: Remote Objects Timing, reference: remote);
• the cost of passing a  Hashtable  object, as a function of the number of items, each item being a short string (table/graph: Hashtable Serialization Timing);
• the cost of passing a  String  object, as a function of the string size (table/graph: String Serialization Timing);
• (not part of RMI) the cost of computing the MD5 signature of a file, as a function of the file size (table/graph: MD5 Signature Timing).

Some conclusions
The Java RMI implementation seems to be quite effective. It is interesting that the first execution of practically any RMI-related method takes significantly longer that the successive calls. This is probably due to the extra time needed to set up sockets and create network object representations. On the other hand, if a method takes a non-trivial data structure (e.g. a  Hashtable  or just a  String  object) as an argument, there is no difference in the time needed for the first and successive calls to this method, i.e. the cost of marshaling/unmarshalling data structures is much larger than setting up sockets. This is true even for relatively small objects, that is why in the tables Hashtable Serialization Timing and String Serialization Timing there is only one extra column marked "1st" which gives the times for the first call of a remote method, taking a 0-size hash table or string as an argument. For other hash table and string sizes there was no significant difference between the first and successive calls.
The times for hash tables and strings serialization, as well as the time for computing the MD5 signature of a file seem to be linear function of the object size (see the least squares approximations given in the graphs).

Measurement methodology
The  System.currentTimeMillis()  method call was used for timing. It was called before and after each block of statements being measured, then the difference was taken. To increase the credibility of the results the following technique was used: to time a particular task, it was iterated in a loop and the total time was divided by the number of iterations. These measurements were performed with school.cs.indiana.edu running the client-side code and guitar.cs.indiana.edu running the server code. In the tables below the leftmost column (num iter) represents the number of iterations in each loop, numbers in each row - average times. The last two rows give the average among all sets of measurements and the standard deviation. For most tasks the very first execution was timed separately. This time is given in a column marked 1st. For these columns the number of iterations from the leftmost column is irrelevant. All times are given in seconds.

Remote Objects Timing
num     nothing        remote        local        lookup         create        bind 
iter   1st   next    1st   next    1st   next    1st   next    1st   next    1st   next 
----------------------------------------------------------------------------------------
  10  0.005  0.003  0.041  0.011  0.204  0.010  2.974  0.017  1.378  0.001  1.049  0.041
  17  0.007  0.003  0.052  0.009  0.167  0.013  2.732  0.019  1.353  0.001  1.086  0.041
  24  0.004  0.003  0.043  0.011  0.191  0.011  2.772  0.014  1.247  0.001  0.919  0.034
  33  0.004  0.005  0.044  0.012  0.277  0.009  2.890  0.011  1.263  0.001  0.950  0.041
  47  0.004  0.003  0.045  0.010  0.170  0.012  2.200  0.010  1.363  0.001  0.913  0.037
  52  0.005  0.004  0.069  0.011  0.147  0.011  2.443  0.011  1.795  0.002  1.848  0.053
  64  0.005  0.004  0.069  0.011  0.147  0.011  2.268  0.013  2.331  0.001  1.899  0.061
  77  0.003  0.004  0.039  0.011  0.188  0.011  2.507  0.011  2.186  0.001  1.301  0.046
  91  0.005  0.004  0.040  0.010  0.227  0.010  2.561  0.012  1.540  0.001  1.417  0.043
 128  0.004  0.004  0.039  0.010  0.220  0.011  2.324  0.012  1.718  0.001  1.552  0.047
----------------------------------------------------------------------------------------
avrg  0.005  0.004  0.046  0.011  0.205  0.011  2.567  0.013  1.617  0.001  1.293  0.044
sdev  0.001  0.001  0.009  0.001  0.040  0.001  0.253  0.003  0.365  0.000  0.355  0.007



Hashtable Serialization Timing
num                         number of items 
iter  1st(0)   0      5     17     29     64     249    485   1001   2055 
--------------------------------------------------------------------------
   5  0.029  0.009  0.018  0.023  0.031  0.057  0.176  0.329  0.754  1.483
  12  0.024  0.006  0.013  0.024  0.033  0.059  0.179  0.354  0.705  1.477
  19  0.046  0.006  0.013  0.022  0.033  0.054  0.184  0.330  0.705  1.457
  24  0.034  0.007  0.015  0.023  0.031  0.060  0.179  0.339  0.697  1.477
  28  0.041  0.006  0.013  0.024  0.034  0.055  0.183  0.333  0.699  1.460
  31  0.023  0.007  0.012  0.025  0.035  0.057  0.182  0.336  0.703  1.483
--------------------------------------------------------------------------
avrg  0.033  0.007  0.014  0.023  0.033  0.057  0.180  0.337  0.710  1.473
sdev  0.008  0.001  0.002  0.001  0.001  0.002  0.003  0.008  0.020  0.010



String Serialization Timing
num                         string length (bytes) 
iter  1st(0)  0      10     34     58     128    498    970   2002   4110 
--------------------------------------------------------------------------
  10  0.004  0.005  0.004  0.008  0.004  0.005  0.013  0.026  0.037  0.063
  21  0.005  0.003  0.004  0.004  0.005  0.009  0.013  0.025  0.034  0.068
  45  0.005  0.005  0.004  0.006  0.006  0.006  0.014  0.023  0.035  0.063
  76  0.004  0.004  0.004  0.005  0.005  0.006  0.014  0.022  0.037  0.067
  98  0.011  0.004  0.005  0.005  0.006  0.006  0.014  0.024  0.038  0.069
 128  0.005  0.004  0.004  0.004  0.005  0.007  0.014  0.022  0.037  0.064
--------------------------------------------------------------------------
avrg  0.006  0.004  0.004  0.005  0.005  0.007  0.014  0.024  0.036  0.066 
sdev  0.002  0.000  0.000  0.001  0.001  0.001  0.001  0.002  0.001  0.002 



MD5 Signature Timing
num                         file size (bytes) 
iter      0    512    769   1024   3116   4096  23456  65432 131072 178176 
--------------------------------------------------------------------------
  10  0.003  0.014  0.018  0.027  0.069  0.075  0.479  1.265  2.573  3.555
  13  0.003  0.013  0.014  0.019  0.053  0.069  0.412  1.092  2.341  3.115
  16  0.004  0.011  0.020  0.026  0.070  0.086  0.443  1.243  2.483  3.295
  21  0.002  0.010  0.017  0.019  0.051  0.076  0.423  1.104  2.147  2.986
  25  0.002  0.011  0.016  0.021  0.063  0.066  0.439  1.155  2.148  2.981
  32  0.002  0.018  0.023  0.024  0.068  0.070  0.406  1.115  2.361  3.122
--------------------------------------------------------------------------
avrg  0.003  0.013  0.018  0.023  0.062  0.074  0.434  1.163  2.342  3.176 
sdev  0.001  0.003  0.003  0.003  0.007  0.006  0.024  0.068  0.158  0.199