Archive for September, 2009


Testing log statements

September 25, 2009

Of late, this blog has become an almost exclusive chess blog. Let me redress that balance, at least for one post.

Unit testing your log statements is unusual, but not unheard of. There might be many reasons for this – you might have a separate process monitoring your log files and taking action on certain log messages…or, you might be handling an event which you choose to ignore except to log its invocation and you want to test that you are logging properly. Whatever the reason, there isn’t any easy way (at least in Java) to test your log statements.

One way of testing is to read from the log file and ensure the log statement gets written out. But we don’t ideally want to be reading from log files in our unit tests. Here’s what you could do, if you were using log4j:

First, have a class called

import java.util.Vector;

import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.spi.LoggingEvent;

public class VectorAppender extends AppenderSkeleton {
 private static Vector <String>messages = new Vector<String>();
 public static final boolean VECTORAPPENDER_SYSOUT = false;

 protected void append(LoggingEvent arg0) {
   System.out.println(arg0.getLoggerName() + "  - " + arg0.getRenderedMessage());
  messages.add(arg0.getLoggerName() + "  - " + arg0.getRenderedMessage());
 public void close() {}
 public boolean requiresLayout() {
  return false;

 public static void clear() {
  messages = new Vector<String>();
 public static Vector<String> getMessages() {
  return messages;

Then, we invoke initLogging() in the setup to our unit test:

public static void initLogging() {
 Properties p = new Properties();
 p.put("log4j.rootCategory", "DEBUG, stdout, LOGFILE");
 p.put("log4j.appender.LOGFILE", VectorAppender.class.getName());
 p.put("log4j.appender.stdout.Threshold", "DEBUG");
 p.put("log4j.appender.stdout", "org.apache.log4j.ConsoleAppender");
 p.put("log4j.appender.stdout.layout", "org.apache.log4j.PatternLayout");
 p.put("log4j.appender.stdout.layout.ConversionPattern", "%d %-5p [%C{1}.%M() %L] - %m%n");


Now, VectorAppender.getMessages() gives you everything that’s been logged and you can assert to your heart’s content!


An ugly (and undeserving) win

September 24, 2009

My fourth game against the same opponent (3 previous games) – I should have lost this in spectacular fashion but my opponent failed to spot the opportunities presented to him. He then proceeded to hang a rook in an endgame he should have been able to convert. My play certainly needs some improvement. Replay.

1. e4 d6 2. d4 Nf6 3. Nc3 g6 4. Be3 c6 5. f3 b5 6. Qd2 Nbd7 7. g4 Nb6 8. Bd3 Nc4 9. Bxc4 bxc4 10. O-O-O Rb8 11. Nge2 Qa5 12. e5 Qb4 13. b3 Qa3+ 14. Kb1 Nd5 15. Nxd5 cxd5 16. exd6 e6 17. Bg5 Bxd6 18. Bf6
Like my previous game with white against the same player, we head into a Pirc. The position is quite even until this point and here the mistakes start.

18… Bb4? 19. Qf4?
I briefly looked at 19. c3 here but was too worried that after the bishop sacrifice, my king would come under an indefensible attack. But I needed to to do two things differently: 1. Realize this was a crucial juncture of the game and regardless of the situation on the clock, spend a considerable chunk of my time here, and 2. Not think in abstractions about my exposed king but rather calculate concrete variations to determine if 19. c3 was playable here. And in fact, it was very much playable, giving me a healthy advantage!
(19. c3! Ba5 (19… cxb3 20. cxb4 Ba6 21. Nc1 bxa2+ 22. Nxa2) 20. Be5 Rb6 21. b4)

19… c3 20. Qc1 Qxc1+ 21. Kxc1 O-O 22. h4 a5 23. a4 Bd7 24. Rd3 Rfc8 25. h5?
25. Kd1 and the bishop capture on a4 doesn’t work. I can just capture the bishop with an advantage. I totally underestimated the strength of the attack, assuming that it wouldn’t work with no queens on the board. Oh how wrong I was!

25… Bxa4 26. hxg6 fxg6 27. Kd1 Bb5 28. Re3 a4 29. Nc1 axb3 30. Nxb3 Bc4 31. Rh2
(31. Nc1)

31… Ra8 32. Nc1 Ra1 33. Rxe6 Ba3 34. Bg5 Rf8
(34… Ra8 35. Rb6 Re8!! 36. Rh1 Bxc1 37. Bxc1 Be2+)

35. Rb6??
Opening the door for 35…Re8 with the line above. Part of the reason I played Rh2 on my 31st move was that I prevent Be2+ winning, if black moved his rook to e8. What I missed was that it now opens up the possibility of capturing twice on c1 and then Re1 is mating! So, after Re8, I’m forced to play Rh1, which then allows Be2+ again! The computer gives this position a -12(!). But there really wasn’t much else I could do. I was close to zugzwang.

35… Rxf3??
Throwing away an easy victory! (35… Re8)

36. Rb8+ Bf8 37. Rh1 Rf2 38. Bh6 Ra7 39. Re1 Raf7 40. Ne2 Rh2 41. Rxf8+ Rxf8 42. Bxf8 Kxf8
42… Bxe2+ 43. Rxe2 Rh1+! 44. Re1 Rxe1+ 45. Kxe1 Kxf8 46. g5 Kf7 47. Ke2 Ke6 48. Kd3 Kf5 49. Kxc3 Kxg5 50. Kd3 h5 51. c4 dxc4+ 52. Kxc4 h4 53. d5 Kf6 and winning – trade all pieces, allowing black to win in the endgame. But it required my opponent to see several good moves, not at all easy in time trouble.

43. Nxc3 Rg2 44. Rh1
(44. Nb1 Rxg4 45. c3 h5 46. Nd2 Bb5)

44… Kg7 45. g5 Rxg5 46. Ne2 Rg2 47. Nf4 h5??
(47… Rg4 48. Ne6+ Kf6 49. Re1 h5 50. c3 Rg3)

48. Nxg2 1-0
Though grateful to win, I can’t take much joy from this game.