09/11/2010

Poznaj swój program

Home

Tematykę IntelliTrace poruszałem już kilkukrotnie. Dzisiaj chciałbym powrócić do zagadnienia opisanego w poście Logi IntelliTrace bez tajemnic czyli analizy logu przy pomocy IntelliTrace API. Tym razem napiszę w jaki sposób dostać się do informacji o tym kiedy została wywołana jakaś metoda, jaki wynik zwróciła i jakie były parametry wywołania. Informacje te są prezentowane w oknie Calls View w Visual Studio 2010 ale można je analizować w ograniczonym stopniu. Poniższe informacje przydadzą się każdemu kto będzie chciał na przykład załadować te dane do bazy danych w celu później analizy, na przykład przy pomocy algorytmów odkrywania wiedzy (data mining).

Zacznijmy od wzorca kodu, który posłuży nam do odczytania pliku z logiem:
using (IntelliTraceFile file = new IntelliTraceFile(pathToIntelliTraceLog))
{
  //Kolekcja procesów będzie miała tylko jedną pozycję
  foreach (IntelliTraceProcess process in traceFile.Processes)
  {
    //Przetworzenie kolejnych wątków
    foreach (IntelliTraceThread thread in process.Threads)
    {
      //Tworzymy strumień ze zdarzeniami. Każde zdarzenie odpowiada np.: wywołaniu metody
      Chain chain = thread.CreateThreadChain<ThreadChain>();
  
      EventToken eventToken = chain.FirstValidToken;
      //Przetwarzamy zdarzenie po zdarzeniu
      while (eventToken != chain.AfterLastToken)
      {
        //Pobranie zdarzenia
        IntelliTraceEvent ev = chain.GetEvent(eventToken);

        //To zdarzenie reprezentujące wywołanie metody
        if(ev is MethodEnterEvent)
          ProcessMethodEnterEvent(ev);
        //To zdarzenie reprezentujące zakończenie wywołania metody
        else if(ev is MethodExitEvent)
          ProcessMethodExitEvent(ev);
          
        eventToken = chain.GetNextToken(eventToken);
      }
    }
  }
}
Powyższy kod zawiera dużo komentarzy dlatego nie powinno być trudności z jego zrozumieniem. Chciałbym zwrócić uwagę tylko na jedną rzecz. Lista zdarzeń jakie możemy obsłużyć zawiera znacznie więcej pozycji niż tylko dwie pokazane powyżej (MethodEnterEvent, MethodExitEvent). Niestety ale nie ma dobrej dokumentacji z pełną listą jaki "łańcuch zdarzeń" jakie zdarzenia udostępnia. Pozostaje droga eksperymentalna oraz przyjrzenie się projektowi iTraceReader, o którym już pisałem w poście Logi IntelliTrace bez tajemnic.

Zobaczmy, więc jak wyglądają metody ProcessMethodEnterEvent oraz ProcessMethodExitEvent. Na samym początku należy zamienić zdarzenia MethodEnterEvent oraz MethodExitEvent, które zawierają tylko suchy ciąg bajtów na bardziej przyjazne ResolvedMethodEnterEvent oraz ResolvedMethodExitEvent, z których łatwo wyciągniemy interesujące nas informacje.
private void ProcessMethodEnterEvent(IntelliTraceEvent ev)
{
  ResolvedMethodEnterEvent methodEnterEvent = new ResolvedMethodEnterEvent(CurrentProcess, ev as MethodEnterEvent);
  //...
}
Klasy ResolvedMethodEnterEvent oraz ResolvedMethodExitEvent zawierają właściwość Method, która zwraca obiekt klasy ResolvedMethod. Klasa ta reprezentuje wywołaną metodę i udostępnia następujące bardzo intuicyjne właściwości:
  • ContainingTypeName - Pełna nazwa typu (razem z przestrzenią nazw) w ramach, którego metoda została zdefiniowana.
  • MethodName - Nazwa metody.
  • ParameterNames - Nazwy (ale nie wartości) parametrów.
  • ParameterTypeNames - Pełne nazwy typów parametrów.
  • ReturnTypeName - Pełna nazwa typu (ale nie wartość) zwracanego przez metodę.
Teraz przejdźmy do odczytania parametrów przekazanych do metody przy jej wywołaniu. Do tego celu posłuży nam metoda:

IList<IDataElement> ResolvedMethodEnterEvent.GetParameters()

W celu reprezentowania różnych bytów IntelliTrace API udostępnia interfejs o nazwie IDataElement. IDataElement może reprezentować typy proste i referencyjne. W przypadku typu referencyjnego IDataElement może zawierać elementy podrzędne reprezentujące składowe obiektu, które również będą reprezentowane przez IDataElement. Napisałem może, a nie musi ponieważ IntelliTrace analizuje tylko obiekty pierwszego poziomu. Czyli jeśli parametr jakiejś metody to obiekt klasy A, który zawiera składowe typu string, int oraz wskazanie na obiekt klasy B to IntelliTrace zapisze w logu wartości wszystkich składowych typów prostych obiektu klasy A ale już nie obiektu klasy B. Na temat obiektu klasy B dowiemy się tylko tyle, że jest. Poniżej zamieszczam opis interfejsu IDataElement. Zaznaczam jednak, że tworząc ten opis bazowałem na doświadczeniu i przeprowadzonych eksperymentach dlatego może on zawierać nieścisłości lub błędy:
  • HasChildren - true jeśli mamy do czynienia z typem referencyjnym i jest to obiekt pierwszego poziomu, false w przypadku typów prostych i obiektów zagnieżdżonych.
  • Name - Nazwa parametru, nazwa składowej obiektu, '[Return value]' dla wartości zwracanej przez metodę, this lub base.
  • TypeName - Pełna nazwa typu reprezentowanego bytu.
  • Value - W przypadku typów prostych właściwa wartość, a w przypadku typów referencyjnych nazwę typu. Jeśli wartość nie została zapisana przez IntelliTrace otrzymamy wynik 'unknown'.
  • GetChildren - Metoda, którą możemy wywołać jeśli właściwość HasChildren jest równa true. Metoda ta zwraca elementy podrzędne w stosunku do bieżącego.
Warto również wiedzieć o poniższej metodzie, która służy do pobrania wyniku zwróconego przez metodę:

IDataElement ResolvedMethodExitEvent.GetReturnValue()

Znacznie rzadziej będą nas interesowały parametry typu out, do których uzyskamy dostęp przy pomocy poniżej metody. Niestety ale wygląda na to, że metoda ta zawiera jakiś błąd. Próbowałem wywołać ją kilkukrotnie dla rożnych metod z parametrem out typu string. Za każdym razem kończyło się to błędem. Raz był to wyjątek ArgumentOutOfRangeException innym razem ApplicationException.

IList<IDataElement> ResolvedMethodExitEvent.GetOutputs()

Podsumowując pomimo ograniczeń IntelliTrace API zachęcam do zabawy z logami.

01/11/2010

Biała bluzka

Home

Czy lubię chodzić do teatru? Nawet bardzo, szczególnie na komedie i mam takie szczęście, że do tej pory nie zawiodłem się na żadnym spektaklu na jakim byłem. O dwóch takich kulturalnych wypadkach pisałem już wcześniej w postach Kobieta pierwotna oraz Dzikie żądze. Dzisiaj ponownie chciałbym wrócić do tej tematyki i napisać parę słów o przedstawieniu "Biała bluzka" z bardzo dobrą rolą Krystyny Jandy, granym w teatrze och-teatr.

Dla wielu ta sztuka oparta o opowiadanie Agnieszki Osieckiej to z pewnością przedstawienie kultowe, coś z serii must-see. Ja o niej wcześniej nie słyszałem i szedłem na nią z pewną obawą, a to dlatego, że preferuję przedstawienia śmieszne i przyjemne, a "Biała bluzka" komedią z pewnością nie jest, chociaż momentami śmiałem się. Właściwie to trudno mi zaklasyfikować tą opowieść o niespełnionej miłości do opozycjonisty do konkretnego gatunku. Sztuka nie posiada fabuły w dosłownym tego słowa znaczeniu, brak w niej dialogów, a na scenie widzimy tylko jedną aktorkę wygłaszającą monolog i śpiewającą.

Teraz nie potrafiłbym dokładnie powiedzieć o czym był ten monolog i piosenki. W pamięci zapadło mi natomiast jak dobrze ten monolog został wygłoszony, a przede wszystkim jak rewelacyjnie zostały zaśpiewane piosenki Agnieszki Osieckiej. Przedstawienie trwało około 2 godzin i pomimo minimalistycznej dekoracji, braku nagłych, trzymających w napięciu zwrotów akcji oraz poważnej tematyki nie nudziłem się. Krystyna Janda była po prostu niesamowita, a jej głos, z lekką chrypką zapamiętam na długo i bardzo żałuję, że nie można było kupić nagrania z tymi piosenkami. Wielka szkoda! Inne elementy przedstawienia jak muzyka, nietypowa aranżacja wnętrza również stały na bardzo wysokim poziomie chociaż dla mnie zostały przytłoczone przez kunszt aktorki. Podsumowując: polecam, polecam i jeszcze raz polecam.

28/10/2010

Znikające Activity

Home

Na poniższym obrazku widać dwa schematy pochodzące z rożnych aplikacji, a przedstawiające fragment pewnego procesu biznesowego. Z prawej strony można zobaczyć definicję tego procesu, a z lewej powołaną do życia i uruchomioną jego instancję.



Niestety ale z jakichś powodów instancja różni się od swojej definicji. Pytanie dlaczego? Początkowo myślałem, że to jakiś problem z zapisywaniem lub odczytywaniem definicji/instancji procesu z bazy danych. Pomysł ten jednak szybko odrzuciłem ponieważ gdyby problem tkwił w tym miejscu to odczyt z bazy danych, deserializacja obiektu i w końcu wyświetlenie definicji/instancji procesu w standardowej kontrolce WorkflowView nie udało by się.

W dalszej kolejności zacząłem szukać różnic pomiędzy wspomnianymi aplikacji. Szybko udało się wykryć (dziękuję za pomoc Tomkowi), że kod brakującego Activity znajduje się w bibliotece niedostępnej dla aplikacji. Po skopiowaniu odpowiedniej dll'ki do katalogu z binariami aplikacji problem ustąpił.

Zacząłem się jednak zastanawiać czemu nie został zgłoszony żaden wyjątek informujący o braku dll'ki. Od razu pomyślałem, że ktoś musiał go przechwycić i zgasić. W sumie to się nie pomyliłem. Po włączeniu Managed Debugging Assistant dla wszystkich wyjątków (Debug -> Exceptions) i ponownym uruchomieniu aplikacji asystent pokazał, że wyjątek pojawia się w czasie deserializowania instancji procesu, gdzieś w środku klasy ActivityMarkupSerializer. Pojawienie się wyjątku nie przeszkadza jednak dokończyć deserializacji i zwrócić obiekt reprezentujący proces tylko, że bez kilku Activity.

Można powiedzieć, że ActivityMarkupSerializer jest bardzo sprytny ponieważ potrafi sobie poradzić nawet jeśli brakuje jakiejś biblioteki. Moim zdaniem ta klasa jest jednak za sprytna. Teraz już będę o tym wiedział ale na takim błędzie można stracić mnóstwo czasu.

27/10/2010

OciEnvCreate failed with return code -1

Home

OciEnvCreate failed with return code -1 to błąd na temat, którego można znaleźć w sieci sporo pytań ale mało odpowiedzi. Ja niestety miałem tego pecha i również na niego trafiłem, a w rezultacie straciłem kilka dobrych godzin. Błąd ten może pojawić się przy próbie nawiązania połączenia z bazą danych Oracle. Z informacji jakie znalazłem wynika, że najczęściej pojawia się w trzech przypadkach:
  • Brak zainstalowanych bibliotek klienckich Oracle.
  • Zła wersja zainstalowanych bibliotek klienckich Oracle.
  • Brak uprawnień użytkownika na jakim uruchomiony jest proces roboczy ASP.NET do katalogu z bibliotekami klienckimi Oracle.
Co do dwóch pierwszych scenariuszy to ani nie zaprzeczę i ani nie potwierdzę ponieważ na maszynie, na której napotkałem problem działał już program łączący się z bazą danych Oracle. W moim przypadku błąd pojawił się w usłudze webowej zainstalowanej na IIS'ie. Początkowo myślałem, że chodzi o coś zupełnie innego ponieważ tylko pierwsze odwołanie do wspomnianej usługi kończyło się błędem. Przy każdym następnym odwołaniu Web Service zachowywał się tak jakby działał tylko, że zwracał niepoprawne wyniki. No cóż pewnie ktoś gasił wyjątek! Przy pierwszym odwołaniu do usługi wołana jest natomiast metoda Application_Start zdefiniowana w pliku Global.asax, która w tym przypadku zawierała kod nawiązujący połączenie z bazą danych.

Kiedy już odkryłem pierwotną przyczynę niepoprawnego działania usługi postąpiłem zgodnie ze znalezioną sugestią i nadałem pełne uprawnienia do katalogów z bibliotekami Oracle, wstępnie użytkownikowi Wszyscy. Jednym z tych katalogów był C:\app\Administrator\product\11.1.0\client_1.

Następnie zrestartowałem pulę aplikacji do jakiej została przypisana usługa i sprawdziłem czy to coś zmieniło. Okazało się, że niestety nie. Spróbowałem jeszcze raz i nic. Po jakimś czasie stwierdziłem, że może chodzi o jakieś inne katalogi i zdesperowany nadałem użytkownikowi Wszyscy uprawnienia do całego dysku. Niestety znowu bez sukcesu. W tym momencie przyszło mi do głowy, że może nie wystarczy nadanie uprawnień i zrestartowanie puli aplikacji tylko trzeba dodatkowo uruchomić ponownie komputer, co też zrobiłem. Okazało się to strzałem w dziesiątkę.

Zadowolony z sukcesu postanowiłem tym razem zrobić wszystko po bożemu czyli cofnąć nadanie uprawnień wszystkim do wszystkiego i nadać pełne uprawnienia tylko jednemu użytkownikowi i tylko do jednego folderu, ewentualnie dwóch ale ściśle określonych. Na początek chciałem się jednak upewnić o jaki konkretnie folder chodzi i jakiego użytkownika. Postanowiłem więc wrócić do stanu początkowego kiedy błąd jeszcze występował. Jakie było jednak moje zdziwienie kiedy okazało się, że jest to niemożliwe ponieważ po cofnięciu nadania uprawnień i restarcie maszyny wszystko działa.

Reasumując niestety ale nie potrafię z 100% pewnością stwierdzić komu, do czego i jakie uprawnienia należy nadać. Faktem jest jednak, że instalator Oracle nie do końca poprawnie konfiguruje system w czasie instalacji. Faktem jest również, że nadanie prawdopodobnie pełnych uprawnień, prawdopodobnie do folderów wymienionych powyżej, prawdopodobnie dla użytkownika na jakim działa proces roboczy ASP.NET i prawdopodobnie restart komputera pomaga. Mam nadzieję, że te prawdopodobne stwierdzenie oszczędzi komuś kilka godzin pracy.

14/10/2010

Dziw nad dziwy

Home

Dzisiaj ponownie napiszę o błędzie z serii UFO. Przyjrzyjmy sie przez chwilę dwóm poniższym zapytaniom:

Zapytanie 1
select * 
from tabela1 t1
where exists ( select 1 from tabela2 t2, tabela3 t3
               where t2.kolumna = t3.kolumna and
                     t3.kolumna = t1.kolumna )


Zapytanie 2
select * 
from tabela1 t1
where exists ( select 1 from tabela2 t2, tabela3 t3
               where t2.kolumna = t3.kolumna and
                     t3.kolumna = t1.kolumna ) and 
t1.data = '14-10-2010'


Każdy zapewne zauważył, że drugie zapytanie różni się od pierwszego tylko dodatkowym warunkiem w zapytaniu zewnętrznym. Innymi słowy zapytanie 2 zawęża wynik jaki otrzymany w zapytaniu 1. A teraz pytanie:

Czy zapytanie 2 może zwrócić wiersze, które nie zostaną zwrócone przez zapytanie 1?

Część z was zapewne stuka się teraz w głowę i zastanawia się po co pytam o rzeczy oczywiste. Odpowiedź jest oczywiście oczywista i brzmi NIE ale, o zgrozo, nie dla każdej bazy danych. Niestety, w przypadku Informix'a w wersji 10 w ''sprzyjających'' warunkach odpowiedź będzie brzmiała TAK. Tak wiem, ja też przecierałem oczy ze zdziwienia kiedy koleżanka z pracy pokazała mi wynik dwóch powyższych zapytań.

Niestety dokładnych przyczyn problemu mogę tylko podejrzewać ale znam jego rozwiązanie. Otóż okazało się, że problem ustąpił po przeliczeniu statystyk przy pomocy poniższego polecenia:
UPDATE STATISTICS LOW 
FOR TABLE table_name (column1, column2...) DROP DISTRIBUTIONS
Polecenie to oblicza statystyki na tzw. niskim poziomie czyli przy założeniu, że rozkład wartości w danych kolumnach jest równomierny. Dodatkowo usuwa rozkłady wartości wyznaczane przy obliczaniu statystyk na poziomie średnim lub wysokim. Tak czy inaczej to ewidentny błąd w optymalizatorze zapytań, mechanizmie indeksów czy też statystyk, który obniża zaufanie do bazy danych.

Na koniec podziękowania dla Agnieszki, która pokazała mi ten błąd oraz dla Marcina, który znalazł rozwiązanie.