Troy posted a comparison of some C# logging code and a simple translation to Smalltalk - and then noticed that the Smalltalk code was a lot slower (nearly 5x). Well, this calls for the profiler. I got the same results for all three of his scenarios in Smalltalk, so I'll compare the code for the class test and for the instance test. First, I loaded Troy's code. Second, I went to the Parcel Manager and loaded the Advanced Tools (there's a legacy name for you) - which brings in the profiler. Profiling the code:

 
 
 

TimeProfiler profile: [TimeLoggers timeClassLogger: 200000].

Leads to this result:

You can click through to see the larger view. The upshot is, the original logging code sends #today to class Date multiple times within the logging code (instead of once). Additionally, it turns out that #expandMacrosWith: - while convenient - is fairly expensive. You can see all that in the expanded view. In any case, here's the original code:

 
 
 

writeToLog: aString 
	(self fileStream)
	       nextPutAll: ('%<!--         
<1p>/<2p>/<3p>' 
	                               expandMacrosWith: Date today
dayOfMonth
	                               with: Date today monthIndex
	                               with: Date today year)
 

To change the performance, I did two things. First, I changed the code above to just print the string that was sent in, and then I changed the calling code to send in the string with the Date formatted. I could have encapsulated that in the new code for the above, but in any case, here's the new caller:

 

       1 to: iterations
	       do: 
	               [:i | 
	               si 
	                       writeToLog: ('Testing write to log via
basic logger - line number ', i printString,  
	                                       ' ', todayString)].

A better variation would have the todayString done in the logger - it doesn't force work on the user of the code. In any case, this variation yields logging code that is still slower than the C# code, but not absurdly so. I also posted that - 1.1 is the faster (but less well coded) version, with 1.2 being the better way. That code has the caller simply send in a string, to which the date will be appended, as follows:

 

   | todayString |
	todayString := Date today printFormat: #(2 1 3 $/ 1 1 ).
	(self fileStream)
	       nextPutAll: '<--  ';
	       cr;
	       nextPutAll: aString, ' ';
	       nextPutAll: todayString;
	       cr;
	       nextPutAll: '-->';
	       cr;
	       flush

On my system, that runs a a bit faster than the better encapsulated version, but not much.

The upshot of all this? Two things:

• Direct translations of code rarely lead to good results. Each language system has strengths and weaknesses, and direct translations don't hit the strengths
• Never make guesses about performance - run the profiler.

Again, all the code for this is in the public Store.