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.

Nie przegap kolejnych postów!

Dołącz do ponad 9000 programistów w devstyle newsletter!

Zapisując się na newsletter zgadzasz się na przetwarzanie Twoich danych osobowych w celu wysyłania na wskazany przez Ciebie adres e-mail informacji handlowych o nowościach, promocjach, produktach i usługach związanych z serwisem devstyle.pl. Będzie to marketing bezpośredni, do realizacji którego wykorzystam Twoje telekomunikacyjne urządzenia końcowe. Administratorem Twoich danych osobowych będzie Maciej Aniserowicz prowadzący działalność gospodarczą w Białymstoku (15-215) przy ul. Konopnickiej 14/8, NIP 5422824401. Przysługuje Tobie prawo do cofnięcia zgody, żądania wglądu do Twoich danych, wniesienia sprzeciwu co do ich przetwarzania, sprostowania, usunięcia i ograniczenia przetwarzania. Więcej informacji o tym jak przetwarzam Twoje dane znajdziesz na devstyle.pl/RODO. Powered by ConvertKit
Notify of
Jacek
Jacek

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

procent

@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

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

Od czego adnotacje [Fact]?

Korzystanie z Refleksji(?) daje cechy Lispa :)

procent

@Soltys:
[Fact] z xUnit.

bszafko

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

procent

@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

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

@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

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

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

procent

@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

Ha. Od CompositeKeys trzymam się z daaaaaleka :)

Kurs Gita

Zaawansowany frontend

Szkolenie z Testów

Szkolenie z baz danych

Facebook

Książka

Zobacz również