Tuesday, December 27, 2011

Building Lego Super Car

First of all this is not really about java, but hell, we have christmas now, and its allowed to have fun from time to time, isn't it? And as I first started to play around with Lego Mindstorms, I seriously wanted to program it with Java one day, which never came.
With time I realized that my engineering skills are far underlaying my programming skills, and thus I would never be able to build the robot I promised my wife. Originally I planed to build a robot, which would react to the sound of the crying baby (sound sensor) find the baby carriage (camera) and start to swing it until the baby is calm again. Well my oldest daughter is 8 now.
However, over time I reduced my pretensions and start to enjoy building complex lego  models for fun. Just what men do. If not, why would they build a special site for it? ;-)
This one is probably the best I ever built and second best after the unimoc. However, the Lego Super Car is a superior example what amazing models can be build with lego, and how complex technical aspects can be explained by playing ;-)

But enough said, we lets unpack the package. This is how the box have looked like:


 First glance inside:






























First, sorting the parts:


After an hour everything is sort and prepared: 







Finally, first building step (128 to follow):



In the meantime, some other duties had to be fulfilled: 



and the concentration refilled: 


The heart of the modell - the gear: 





























The gear upside-down, the red wheels are moved by the shifter and switch different gears:


The gear block is finally finished: 


And now for something fully different: 



The motor is attached to the gear block:






























The base of the car is ready:


Suspension of the back wheels: 


Transmission of power to the back wheels:


Progress report, the seats are attached: 


I am always amazed by the engine, this one is V8 and moving ;-)


Engine assembled:


Big moment, the engine gets inserted: 



Enough for first day. As I realized next day the engine was beveled ;-) But now the car got a steering wheel, what could you possibly want more:



DAY TWO


Finalizing the car:



Unexpectedly, some help showed up (not that I asked for it, but some offers can't be declined...):



And another helping hand. Kids can work with stickers much better than I do:



Finally, everything but the casing is done:


Truly, big moment, the battery pack is the last thing left (and the wheels):


Ladies and gentlemen, THE TRULY SUPER CAR!



My other lego cars came by to welcome the new one in the family ;-)






























A video with the power functions will be uploaded later ;-)
All in one, great fun, great car, great challenge.











Thursday, December 22, 2011

The three most fatal bugs, ever.

There are bugs and then there are BUGs. The bugs are usually fixed and forgotten, but BUGs remain with you forever. I'd like to tell about three, that are worth telling.

The first one occurred (do bugs actually occur? pardon my english ;-) ) as I was working for FriendScout in 2005. We had a nice monitoring tool, which had a table representing the production system with a row for each webserver in the farm, and it changed the color according to the status of the server. If the server was replying it was green and if not - red. Once in August it started to switch red. One server after the next. And after the forth server it was over. The situation repeated. Once, twice, thrice... We had searched and search and had found nothing. It looked like it was a user which was doing something weird, that killed the server, but what?

Finally, Oliver, a fellow engineer, has found it, and it was a picture. But not just a picture, it was a pdf file named jpg. A lady wanted to upload a picture, which was a pdf. Pdf's weren't supported mime types (only jpegs and gifs were back then), so the upload servlet rejected the file. But the lady was (or thought she was) smarter than us and renamed the file to jpg. Now it passed the mime-check all-right and was passed over to the image processing software, a more or less standard tool which was called imagemagick. But the tool was also smarter than us and ignored the file name, extension and mime-type all together, instead it looked into the file and detected it was a pdf. After this glorious discovery it tried to call a pdf processing tool - ghostscript. But since we never actually wanted to process or even accept pdfs, ghostscript wasn't installed on the servers and the attempt to start it crashed the imagemagick lib. Since the code was native it took the whole JVM with it. Ouch.

The second bug is the power of the debug log. Back in prehistoric version of ASG I was hacking a very first version of this site. It worked absolutely great, the customer loved it and everything. After some time the customer called me and told me that the site was getting slower each day. I looked at my local copy - fast as wind. Live installation - everything ok, but adding new items (machines back then) lasts about a minute. I was searching for the bug for three days, as the customer called again, and said that creating new cms items is now about 2 minutes each, and that the only thing he did was adding 100 items. Now it was at least something. I double-checked the logs - nothing. I reviewed the code - nothing. I had no good profiler (yes, if I had MoSKito back than, I would have found it faster), so I started to add time measurements everywhere, and, after a long hunt, I finally found the line - it was a log.debug statement.

The service that was responsible for storing the items in the cms had one small innocent line: log.debug(cache).  Since debug output was off, the log call had no visible effect, hence I had nothing in logs, but the cache got bigger and bigger with each added item, and the effort to execute its toString method, which printed out all contained elements, was growing constantly. From 0 seconds in the unit test to 180 in production. That teached me to use if log.isDebugEnabled()... At least something ;-)

And this was the second bug. Now for my personal all time favorite, super-bug we have to return back in text and time. It also happened at FriendScout but 2003, before they hired me (and this may well have been the reason why ;-)) The platform was pretty unstable and run by people, who were thinking more like admins as like developers. And since the admin usually doesn't understand, why something is broken, he has a standard method to fix things -> the infamous alt-ctrl-del button. In this case it was a little bit more subtile that that, so some smart (admin) guy wrote a script that was watching the log files and searching for the keyword 'FATAL' in it. If it would find an occurrence of FATAL, it would assume a bad-bad-bad error happened and  trigger a full application restart. And there were some of the restarts in the year until they had to review this strategy. The reason for the review was a customer who called the customer desk and asked: "why does the system ALWAYS crash when I log in?" 


The answer was easy, it was her login name. It was femme_fatale.


So what about you? Do you have funny bugs worth mentioning? Tell me please! ;-)


Using asynchronous method calls to mine gold faster.

Disclaimer:
First of all let me say, that we are not going to mine any real gold here. However, gold mining seemed as a good example, since the wins through asynchronous communication can be as valuable.
Second, code examples in this post rely on a specific programming language (java) and a specific framework (will be named at the end) but can well be used with any other language or framework. Talking about frameworks, asynchronous communication is all but trivial and its of great value to have a synchronously programmable framework which hides the details from the developer.

Lets go back a century or two and dig for some gold. For that we have developed a special service which offers two methods:

@DistributeMe(asynchSupport=true, asynchCallTimeout=2500)
public interface GoldMinerService extends Service{
/**
* Searches a random location for gold. Can last up to 10 seconds. 
* Returns if anything was found.
* @return
*/
boolean searchForGold();
/**
* Washes gold for a given duration. Returns the amount of washed clumps.
* @param duration
* @return
*/
int washGold(long duration);
}

You probably noticed the @DistributeMe annotation on the top of the class. More on it later.


The first method searches for gold at a location. When we call it, it picks a random location and starts digging. It digs for several seconds (1 to 10) making a meter per second until it finds something. And than this something can be gold or clay. Two gold miners are using this service, the SynchGoldSearcher and the AsynchGoldSearcher. Both have 60 seconds to find possible locations for a gold mine.
The SynchGoldSearcher is pretty straight forward, it just digs until it hits something. Just like the classical service call does. So please allow me to introduce Player1:


public class SynchGoldSearcher {
public static void main(String[] args) throws Exception{
GoldMinerService service = ServiceLocator.getRemote(GoldMinerService.class);
long start = System.currentTimeMillis();
int searchTime = 60;
System.out.println("Searching for gold for "+searchTime+" seconds");
long endTime = start + 1000L*searchTime;
long now;
int foundGold = 0;
int attempts = 0;
while ((now = System.currentTimeMillis())<endTime){
System.out.println("Attempt "+(++attempts));
if (service.searchForGold()){
foundGold++;
System.out.println("Found gold!");
}else{
System.out.println("Nothing here...");
}
}
System.out.println("Found "+foundGold+" gold in "+attempts+" attempts and "+(now - start)/1000+" seconds.");
}
}

There is no real magic in the above code, so I'll skip the comments. Now the second player looks pretty similar except for a small detail:


public class AsynchGoldSearcher {
public static void main(String[] args) throws Exception{
GoldMinerService service = ServiceLocator.getAsynchRemote(GoldMinerService.class);
long start = System.currentTimeMillis();
int searchTime = 60;
System.out.println("Searching for gold for "+searchTime+" seconds");
long endTime = start + 1000L*searchTime;
long now;
int foundGold = 0;
int attempts = 0;
while ((now = System.currentTimeMillis())<endTime){
System.out.println("Attempt "+(++attempts));
try{
if (service.searchForGold()){
foundGold++;
System.out.println("Found gold!");
}else{
System.out.println("Nothing here...");
}
}catch(CallTimeoutedException timeoutException){
System.out.println("too deep, aborted...");
}
}
System.out.println("Found "+foundGold+" gold in "+attempts+" attempts and "+(now - start)/1000+" seconds.");
((AsynchStub)service).shutdown();
}
}

First it asks for an AsynchRemote instead of a 'normal' Remote. Second, a CallTimeoutedException comes into play.
Remember the annotation @DistributeMe on top of the class? It belong to the distributeme framework and tells it to generate RMI code for my interface. Among other stuff it tells the framework that I want to have an asynchronous stub and that the default timeout for calls over this stub are 2500 ms. This means that any call that lasts longer than 2500 ms will be aborted and a CallTimeoutedException will be thrown.
Now lets start both searchers:
The synchronous searcher provides this, shortened output:

Searching for gold for 60 seconds
Attempt 1
Nothing here...
Attempt 2
Nothing here...
...

Attempt 7
Found gold!
...

Attempt 10
Nothing here...
Found 1 gold in 10 attempts and 65 seconds.



The asynchronous searcher provides this, also shortened output:

Searching for gold for 60 seconds
Attempt 1
too deep, aborted...
Attempt 2
Nothing here...
Attempt 3
too deep, aborted...
Attempt 4
too deep, aborted...
Attempt 5
Found gold!
Attempt 6
too deep, aborted...
Attempt 7
Found gold!
...
Attempt 28
too deep, aborted...
Found 6 gold in 28 attempts and 62 seconds.


The asynchronous approach seems to have been more successful? I admit, I run the test multiple times to achieve the results I wanted, but the number of found mining locations are not that important to the showcase as the number of the attempts. The client doesn't really know, how long the server will need to answer the request. In fact there are situation when an RMI call will hang nearly forever on the server side, and you'll be unable to do anything about it. With asynchronous approach the calling thread is detached from the call and from the server side processing, therefore allowing you (or the framework) interrupt it at any time and return.

When can it be useful? There are many scenarios, but the most important is the quality of service to the user. With this approach you can guarantee that the site will be responsive and answer within acceptable limits (even if some times this answer will be: I can't get this information right now).

But wait, we are just getting warm. Most of the web applications and especially portals have pages where they need to combine multiple pieces of information. Often the process of retrieving the information is long and retrieving the information sequentially sums up many long retrievals. Ironically, often enough the resources in question are not competing (for example two database servers) and we could speed up the retrieval by getting the information in parallel, but its just such a hassle to do all the concurrency programming. Thankfully its not ;-)

To demonstrate this, here is another example. After we got some productive mines in previous section we are now wash mined gold. To achieve this we call the method washGold which washes the gold for given amount of time, producing one clump in each second. Again, we have a synchronous and an asynchronous versions, first the synchronous one:


public class SynchGoldWasher {
public static void main(String[] args) throws Exception{
GoldMinerService service = ServiceLocator.getRemote(GoldMinerService.class);
int washTime = 10;
System.out.println("Washing gold for "+washTime+" seconds.");
long start = System.currentTimeMillis();
int washed = service.washGold(washTime*1000L);
long duration = System.currentTimeMillis() - start;
System.out.println("Washed "+washed+" gold clumps in "+duration+" ms.");
}
}

and now the asynchronous one:

public class AsynchGoldWasher {
public static void main(String[] args) throws Exception{
GoldMinerService service = ServiceLocator.getAsynchRemote(GoldMinerService.class);
AsynchGoldMinerService asynchService = (AsynchGoldMinerService)service;
int washTime = 10;
int calls = 5;
System.out.println("Washing gold for "+washTime+" seconds in "+calls+" calls.");
long start = System.currentTimeMillis();
MultiCallCollector collector = new MultiCallCollector(calls);
for (int i=0; i<calls; i++){
asynchService.asynchWashGold(washTime*1000L, collector.createSubCallHandler(""+i));
}
collector.waitForResults(11000);
int washed = 0;
for (int i=0; i<calls; i++){
washed += (Integer)collector.getReturnValue(""+i);
}
long duration = System.currentTimeMillis() - start;
System.out.println("Washed "+washed+" gold clumps in "+duration+" ms.");
asynchService.shutdown();
}
}

Again, we compare them against each other, first the synchronous one:

Washing gold for 10 seconds.
Washed 10 gold clumps in 10193 ms.


and the asynchronous one:


Washing gold for 10 seconds in 5 calls.
Washed 50 gold clumps in 10200 ms.


Now this is a difference! 5 Times faster? Well, of course it was an easy win, since you as a smart reader already noticed that I'm starting the 5 calls in parallel. But the actually amazing thing is that its achieved with minimal code overhead!
If we take a look at the source code, we see that we only need few additional lines to change the behavior of sequential code and we are programming sequentially even we run concurrently:

First we create a new collector and tell it that we are going to call 5 methods (calls is 5):

MultiCallCollector collector = new MultiCallCollector(calls);


Than we call the methods asynchronously via the auto generated asynchronous interface. Each calls returns immediately.

for (int i=0; i<calls; i++){
  asynchService.asynchWashGold(washTime*1000L,      collector.createSubCallHandler(""+i));
}


Now we tell the collector that we are ready calling and want to wait for max 11 seconds for results.

collector.waitForResults(11000);


And finally we have to collect the results.

int washed = 0;
for (int i=0; i<calls; i++){
  washed += (Integer)collector.getReturnValue(""+i);
}


And even if we are calling 5 times to the same service, there are no physical limitations to the amount of called services or methods.
So where would you use it? Example one: you have a portal with a welcome page which gets some information from multiple modules in the system: new messages, favorites online, the weather and so on. Instead of waiting for each of the submodules you only need to wait for the slowest one. And if its too slow, you can always abort it by setting the max call duration via timeout or similar.
Another example: you have to perform a complicated and long lasting calculation, you split it in multiple blocks and let multiple nodes calculate parts of it. It could save your scaleability problems, of course only if your problem is generally dividable in multiple subtasks, but most are.

To round it up, the above can very well be achieved by programming it manually and will help you a lot in running a high trafficked site or a non-trivial calculation. You don't need to have a specific framework, but if you want to save yourself the hassle you can use ours ;-)

More on DistributeMe.
Source code of the examples.

Exact instructions how to run the tests on your local machine will be provided later... if requested ;-)