Testowanie kodu wielowątkowego jest nie lada wyzwaniem. Teoretycznie powinno się tego unikać, ale czasami nie ma innego wyjścia. Co robić w sytuacji, gdy w komponencie tworzonym podczas naszego testu uruchamiany jest nowy wątek, a w nim wyskakuje wyjątek? Test oczywiście nie przechodzi, ale wcale niekoniecznie musimy wiedzieć dlaczego tak a nie inaczej się stało. Kiedyś pół godziny straciłem na wgapianie się w monitor zanim wpadłem na to, że w wątku pobocznym wyskakuje wyjątek. Bo jak wiadomo, wyjątek rzucony w nowym wątku nie jest przekazywany nigdzie z powrotem – po prostu gubimy o nim wszelkie informacje.
Dość rozsądnym wyjściem wydało mi się po prostu zalogowanie informacji o tym fakcie i pokazanie jej w wynikach testu. Test nie przejdzie i sam framework do testowania nie będzie dokładnie wiedział co się stało, ale z wyświetloną informacją przed oczami łatwiej będzie nam naprawić błąd.
Testy jednostkowe nie powinny jednak zakładać, że będą wykonane w środowisku z poprawnie skonfigurowanym loggerem. Więcej – podczas testów “prawdziwe” logowanie w ogóle nie powinno się odbywać, w końcu wrzucanie do event logu czy bazy danych (zależność nieakceptowalna jeżeli chodzi o testy jednostkowe!) tony informacji wypluwanych przez system podczas testu jest całkowicie zbędne.
Dlatego też stworzyłem loggera specjalnie na tą okazję. Założenia:
- nie wymagamy żadnego pliku konfiguracyjnego
- logujemy tylko błędy
- bez ingerencji w kod systemu dostajemy się do logowanych przezeń informacji
- logowanie konfigurujemy w jednym miejscu, bez konieczności pamiętania o tym w każdym teście
Z wykorzystaniem frameworka log4net rozwiązanie tego problemu okazało się… banalne. Oto kod logujący to co nas interesuje do strumienia Debug:
1: public class TestAppender : AppenderSkeleton 2: { 3: private static readonly PatternLayout _layout = new PatternLayout("%level %logger %ndc - %message%newline"); 4: 5: public TestAppender() 6: { 7: this.Layout = _layout; 8: } 9: 10: protected override void Append(LoggingEvent loggingEvent) 11: { 12: if (loggingEvent.Level < Level.Error) 13: return; 14: 15: Debug.WriteLine(base.RenderLoggingEvent(loggingEvent)); 16: } 17: }
A oto metoda konfigurująca całą infrastrukturę log4net, zawarta w klasie bazowej dla wszystkich testów jednostkowych:
1: [SetUp] 2: public void SetupLogging() 3: { 4: BasicConfigurator.Configure(new TestAppender()); 5: }
Testowanie wielowątkowości nadal nie jest przyjemne, ale przynajmniej teraz wiem gdzie szukać przyczyny, jeśli coś poszło nie tak.
Dlatego moim zdaniem testowanie takiego problemu to działka testów integracyjnych a nie jednostkowych. W testach jednostkowych zamiast watka odpalającego się w tle wrzuciłbym mocka(polecam framework nMock). Z kolei w teście integracyjnym dodawanie nowych komponentów(tutaj wątek) zachodzi stopniowo, więc jest mniejsze ryzyko, że się pogubimy.
Uzywanie czegokolwiek innego od zamockowanego interfejsu loggera w testowanych klasach to troche herezje ;)
Zdecydowanie odradzam jakiegokolwiek logowania w unit-testach. Nie raz mialem sytuacje w pracy gdy odpalilem unity kogos innego i nagle pewien blad spowodowal ze mialem zasrane pol dysku jakimis smieciami ;) Stopien mojej irytacji mozesz sobie wyobrazic.
@Piotr:
Tak jak napisałem: czasem (z róznych powodów, w tym pomyłek popełnionych we wcześniejszych fazach prac) nie ma niestety innego wyjścia.
@SirMike:
Uzywanie zamockowanego interfejsu loggera to z kolei moim zdaniem OGROMNY przerost formy nad treścią… co ma taki zamockowany logger robic w teście? Przedstawione przeze mnie rozwiązanie nie zasmieci dysku – a jedynie wypisze na konsole bledy z innych watkow.