fbpx
devstyle.pl - Blog dla każdego programisty
devstyle.pl - Blog dla każdego programisty
4 minut

object.LogInfo() – do logowania tożsamości obiektu


02.03.2011

Niedawno przedstawiłem TokenContext, klasę pomocniczą upraszczającą wyławianie kontekstu z masy logów tworzonych w aplikacji wielowątkowej, gdzie wiele operacji przeplata się nawzajem.

Regularnie jednak zdarza się, że interesuje nas nie tyle jedna szczególna operacje co cały cykl życia konkretnego obiektu. Kumpel, z którym pracuję nad "głównym" projektem, zaproponował stosowanie takiej, bardzo prostej, logicznej i przydatnej, konwencji:

  1:  _log.Debug("User#{0} did something", user.Id);

Albo:

  1:  _log.Debug("Order#{0} processed", order.Id);

Oczywiście to uproszczony przykład, ale wiadomo o co chodzi. Dzięki temu przetwarzając logi w poszukiwaniu wszystkich informacji o użytkowniku ID=125 wyfiltruję linijki z tekstem "User#125" i mam czego potrzebowałem.

Ostatnio w mniejszym projekcie postanowiłem przetestować jak można by to uprościć jeszcze bardziej, żeby nie klepać ręcznie nazwy typu i hasha. Rozwiązanie przychodzi do głowy samo, a obrazują je te banalne testy:

  1:  public class ObjectLogInfoTests
  2:  {
  3:      public class WithId
  4:      {
  5:          public virtual int Id { get; set; }
  6:      }
  7:  
  8:      public class WithoutId
  9:      {
 10:          public virtual int SomeOtherProperty { get; set; }
 11:      }
 12:  
 13:      [Fact]
 14:      public void should_return_type_name_with_hash_and_id_if_class_has_Id_property()
 15:      {
 16:          var o = new WithId { Id = 8 };
 17:  
 18:          string logInfo = o.LogInfo();
 19:  
 20:          Assert.Equal("WithId#8", logInfo);
 21:      }
 22:  
 23:      [Fact]
 24:      public void should_return_type_name_if_class_does_not_have_Id_property()
 25:      {
 26:          var o = new WithoutId();
 27:  
 28:          string logInfo = o.LogInfo();
 29:  
 30:          Assert.Equal("WithoutId", logInfo);
 31:      }
 32:  }

Klasa implementująca te założenia jest jeszcze "banalniejsza":

  1:  public static class ObjectLoggingExtensions
  2:  {
  3:      public static string LogInfo(this object @this)
  4:      {
  5:          Type type = @this.GetType();
  6:          var idProperty = type.GetProperty("Id");
  7:          object idValue = null;
  8:          if (idProperty != null)
  9:          {
 10:              idValue = idProperty.GetValue(@this, null);
 11:          }
 12:          if (idValue == null)
 13:          {
 14:              return type.Name;
 15:          }
 16:          else
 17:          {
 18:              return "{0}#{1}".FormatWith(type.Name, idValue);
 19:          }
 20:      }
 21:  }

Dzięki temu podany na początku przykład wygląda teraz tak:

  1:  _log.Debug("{0} did something", user.LogInfo());

Oczywiście narzuca to na system konwencje nazywania właściwości "Id", jednak w tym konkretnym przypadku nie był to problem. Bez wielkiego nakładu pracy można by rozszerzyć tą klasę aby dodatkowo szukała na przykład właściwości o nazwie "[TypeName]Id".

Początkowo przez chwilę zastanowiłem się nad tym, czy wykorzystanie refleksji jest w tym przypadku słuszne ze względów wydajnościowych, jednak… nie oszukujmy się, przy kontakcie z bazą danych takie coś nie ma absolutnie żadnego znaczenia. Testowo puściłem wykonanie podobnej instrukcji w pętli milion razy i zajęło to około sekundy.

Tak czy siak rozwiązanie się póki co sprawdza (chociaż nie pokrywa wszystkich scenariuszy w których loguję informację o obiektach).

Coraz bardziej przekonuję się do tego, że zbudowanie odpowiednich pomocników wokół konceptu "logowania" jest istotną częścią systemu. Logowanie powinno być bezbolesne, momentalne i naturalne. Im mniej klawiszy trzeba wcisnąć do uzyskania informacji w logu – tym lepiej.

0 0 votes
Article Rating
12 Comments
Oldest
Newest Most Voted
Inline Feedbacks
View all comments
Jacek
Jacek
13 years ago

Może napiszesz kilka słów o tym jakie informacje logujesz? Czy używasz różnych "leveli" loga – INFO, WARN, DEBUG, ERROR etc.?

procent
13 years ago

@Jacek:
Dobry pomysł. Mam zakolejkowany jeszcze jeden post o logowaniu (powinien się ukazać jutro), potem faktycznie może napiszę o poziomach logowania i moim do nich podejściu. Dzięki za sugestię.

Gutek
13 years ago

Spoko, lubie extension methods i widze ich sens, jednak zwabil mnie tytul bo zatanawialem sie o jaka tozsamosc Ci chodzi – taka mala zmylka w temacie ;)

Soltys
13 years ago

Od czego adnotacje [Fact]?

Korzystanie z Refleksji(?) daje cechy Lispa :)

procent
13 years ago

@Soltys:
[Fact] z xUnit.

bszafko
13 years ago

dodaj sobie jeszcze cache dla GetProperty dla konkretnego typu, oszczedzisz sporo czasu

procent
13 years ago

@bszafko:
Pewnie tak, w mvc2 agresywne cache’owanie takich rzeczy podobno znacząco wplynelo na ogolna wydajnosc frameworka… Akurat w pisanym systemie nie bedzie to mialo zadnego znaczenia wiec i nie ma sensu komplikowac. Ale przy duzych projektach pewnie warto.

dario-g
13 years ago

Hmm… Nie wiem jak Ty, ale ja jeśli mam obiekty, które mają właściwość ‘Id’ są to zazwyczaj obiekty domenowe implementujące dany interfejs. Czy nie lepiej jest zastosować rozszerzenia oparte właśnie o interfejs? :) Wiem, że to prowadzi do pewnych ograniczeń, ale wyklucza całkowicie narzut na refleksję :)

procent
13 years ago

@dario-g:
Obiekty domenowe implementują u mnie interfejs
public interface IEntity {}

pusty, bez niczego więcej, tylko po to żeby FluentNH wiedział co zmapować. Tak naprawdę obiekty te nie mają ze sobą nic wspólnego, więc nie widzę powodu dla którego miałyby implementować wspólny interfejs (który faktycznie wymuszałby jakikolwiek kod).

dario-g
13 years ago

@Procent:
U mnie z kolei implementują
public interface IEntity<T> { T Id { get; }}

stąd mój wcześniejszy komentarz :)

procent
13 years ago

@dario-g:
OK, rozumiem:). Próbowałem z takim podejściem, ale w końcu zrezygnowałem. Nie widzę żadnych korzyści (poza ext. method pobierającą Id:) ).
Dodatkowo ograniczało to wykorzystanie CompositeKeys. Co prawda lepiej w ogóle ich nie mieć, ale gdy już się zdarzy to nie chciałbym się natknąć nagle na taki interfejs.

dario-g
13 years ago

Ha. Od CompositeKeys trzymam się z daaaaaleka :)

Kurs Gita

Zaawansowany frontend

Szkolenie z Testów

Szkolenie z baz danych

Książka

Zobacz również