Controles de tempo de execução de aplicativos de software integrados

A publicação apresenta uma implementação de software de ferramentas internas para coletar e acumular informações métricas sobre o tempo de execução de aplicativos gravados em C / C ++ / C #.

A essência da abordagem descrita é baseada na inclusão de "pontos de controle" no código do programa do aplicativo para extrair dados sobre o tempo de execução de componentes estruturais: métodos, funções e {} blocos. As informações métricas extraídas são acumuladas em um banco de dados interno, cujo conteúdo no final do aplicativo é convertido em um formulário de relatório de texto salvo em um arquivo. A adequação do uso dos meios de controle interno do tempo de execução se deve à necessidade de identificar áreas problemáticas do código, analisar as causas da degradação temporária do aplicativo: total ou parcial, ou aparecendo em determinados conjuntos de dados de origem.

Os exemplos de código-fonte C ++ / C # fornecidos demonstram possíveis implementações da abordagem descrita.

1. Introdução


O desenvolvimento de um aplicativo de software a cada iteração (por exemplo, o lançamento do próximo lançamento) de seu desenvolvimento evolutivo inclui as seguintes etapas básicas:

  • desenvolvimento e teste de funcionalidade;
  • otimização de recursos consumidos de RAM;
  • estabilização de métricas de tempo de execução.

Essas etapas requerem uma quantidade significativa de desenvolvedores, não apenas criativos (como o desenvolvimento e implementação de algoritmos eficazes, a construção de uma arquitetura de software flexível etc.), mas também trabalho de rotina. A última categoria inclui atividades destinadas a estabilizar métricas de tempo para execução de aplicativos. Em muitos casos, esse é um procedimento bastante doloroso quando os desenvolvedores se deparam com a degradação, que é uma conseqüência da expansão da funcionalidade do produto de software, da reconstrução da arquitetura do software e do surgimento de novos threads no aplicativo. Ao mesmo tempo, as fontes de degradação exigem alguns esforços para detectá-las, o que é alcançado não apenas pela alta diligência e responsabilidade dos desenvolvedores (condição necessária), mas também pela composição das ferramentas utilizadas para esses fins (condição suficiente).

Uma das abordagens eficazes para resolver o problema de analisar as métricas de tempo do aplicativo é o uso de produtos de software especializados, por exemplo, GNU gprof . A análise dos relatórios gerados por essas ferramentas permite identificar “gargalos” (métodos e funções de classe), que representam uma quantidade significativa de tempo gasto na execução do aplicativo como um todo. Ao mesmo tempo, a validade do tempo gasto na execução de métodos e procedimentos é certamente qualificada pelos desenvolvedores.

Deve-se notar também que os produtos de software dessa classe, em regra, realizam análises métricas do tempo de execução do código do programa nos níveis de métodos de classes e funções, ignorando os níveis mais baixos (mas mesmo assim significativos do ponto de vista da análise do problema): {...}, por, enquanto, faça até, se - senão, blocos try-catch , dentro dos quais não ocorrem despesas menos significativas de tempo de execução.

A seguir, é considerado o conteúdo principal de uma das possíveis soluções para a implementação de ferramentas de controle de tempo de execução internas, com o objetivo de extrair e acumular informações detalhadas sobre as métricas de tempo dos blocos de software controlados com a geração subsequente de relatórios para desenvolvedores.

Métodos para recuperar dados de tempo de execução


A funcionalidade de qualquer aplicativo de software pode ser interpretada como uma máquina abstrata com um conjunto finito de estados únicos {St} e transições {Tr} entre eles.

Na estrutura dessa abordagem, qualquer fluxo de execução no aplicativo deve ser interpretado como uma sequência ordenada de seus estados e transições entre eles. Nesse caso, a estimativa dos custos do tempo de execução é realizada somando as métricas de tempo em todo o conjunto de estados passados, ignorando os custos das transições de um estado para outro - como valores desprezíveis.

A extração e acumulação de dados no tempo de execução do aplicativo nos pontos de controle especificados é a principal tarefa resolvida pelas ferramentas de controle internas descritas abaixo.

Para cada ponto de interrupção declarado no código-fonte, colocando
A macro PROFILE_ENTRY C ++, o número de passagens durante a execução do aplicativo é registrado e a métrica de tempo - o tempo total em que o aplicativo esteve no estado desde o momento em que o ponto de verificação passou para o próximo nível da hierarquia do programa (incluindo um bloco, método de classe, função, etc.) conforme ilustrado no diagrama abaixo.

O controle dos pontos de controle (registro inicial e cálculo de suas métricas de tempo) é realizado pelo objeto 'timeManager' , criado em uma única instância. Cada evento de passagem no ponto de verificação é corrigido pelo objeto 'timeManager' e , durante a primeira passagem, é registrado por ele como observáveis ​​como 'registerEntry' .

No momento de cada passagem do ponto de controle, um timerObject é criado, fixando o tempo de sua criação. O tempo de execução é fixado no ponto de verificação quando o aplicativo sai do nível atual da hierarquia do software. Nesse momento, o timerObject do objeto é destruído automaticamente, o que é acompanhado pelo cálculo de sua "vida útil" T. Como resultado, o timeManager aumenta o número de vezes que o ponto de verificação passa e o tempo gasto por T. Para todos os pontos de controle definidos, o timeManager acumula dados com a liberação subsequente de um relatório quando o aplicativo termina.



Abaixo está o código C ++ de origem que implementa as ferramentas internas para controlar o tempo de execução do aplicativo.

//     #include <vector> #include <map> #include <algorithm> #include <stdio.h> #include <time.h> typedef unsigned long LONGEST_INT; // ,    //     //     //  ( )   // ()   //    #define PROFILER_ENABLED // CREATE_PROFILER  timeManager , //     // 'main()' #ifdef PROFILER_ENABLED #define CREATE_PROFILER timeManager tManager; #else #define CREATE_PROFILER //   CREATE_PROFILER. #endif //INITIALIZE_PROFILER    timeManager  //       //   'main()' #ifdef PROFILER_ENABLED #define INITIALIZE_PROFILER bool timeManager::object = false;\ std::vector<registerEntry> timeManager::entries; #else #define INITIALIZE_PROFILER //   INITIALIZE_PROFILER. #endif //DELAY(_SECONDS)   '_SECONDS' . //    ,  //     //  #ifdef PROFILER_ENABLED #define DELAY(_SECONDS) {clock_t clk_wait=clock()+((double)_ARG)*CLOCKS_PER_SEC;\ while(clock()<clk_wait) {}} #else #define DELAY(_SECONDS) //    DELAY. #endif //     , //     UNIX  WINDOWS //      #ifdef PROFILER_ENABLED #define MERGE2(x,y) x##y #define MERGE1(_X,_Y) MERGE2(_X,_Y) #if WIN32 #define UNIQUENAME prefix,postfix) MERGE1(prefix,postfix) #else #define UNIQUENAME(prefix,postfix) MERGE2(prefix,postfix) #endif #define GEN_SRC(_ARG1,_ARG2) static int UNIQUENAME(ind,_ARG2)=-1;\ if(UNIQUENAME(ind,_ARG2)<0)\ UNIQUENAME(ind,_ARG2)=timeManager::add_entry(_ARG1);\ timeManager::incr_counter(UNIQUENAME(ind,_ARG2));\ timerObject UNIQUENAME(tm,_ARG2)(UNIQUENAME(ind,_ARG2)); //PROFILE_ENTRY      #ifdef PROFILER_ENABLED #if WIN32 #define PROFILE_ENTRY(_TITLE) GEN_SRC(_TITLE,__COUNTER__) #else #define PROFILE_ENTRY(_TITLE) GEN_SRC(_TITLE,__LINE__) #endif #else #define PROFILE_ENTRY(_TITLE) //    PROFILE_ENTRY. #endif //        //    //    ,   timeManager struct registerEntry { //     (  ) std::string entry_name; //     //     LONGEST_INT covers_counter; //      //     (ticks) LONGEST_INT elapsed_time; // registerEntry(const char * title):entry_name(title), covers_counter(0), elapsed_time(0) {} }; //     class timerObject { //   ,     int index; //    clock_t start_time; public: //       timerObject(int ind):index(ind),start_time(clock()) {} //    “ ”  //       //   ~timerObject(void) { timeManager::incr_timer(index,(LONGEST_INT)(clock()-start_time)); } }; //     class timeManager { private: //     static std::vector<registerEntry> entries; // ,     //    static bool object; public: //     //  ,    //     static int add_entry(const char * title) { entries.push_back(registerEntry(title)); return (((int)entries.size())-1); } //       //      static void incr_counter(int profile_entry_id) { entries[profile_entry_id].covers_counter++; } //  'value'     //      static void incr_timer(int profile_entry_id, LONGEST_INT value) { entries[profile_entry_id].elapsed_time += val; } //       //   static void report(void); //  timeManager(void) { if(!object) object = true; else { printf("\n<<>>:    'timeManager' .\n"); throw; } } //        //   virtual ~timeManager(void) {report();} }; //      bool cmp_entries(registerEntry & first, registerEntry & second) { if(first.entry_name.compare(second.entry_name)>0) return false; return true; } //      //    void timeManager::report(void) { const std::string bar(72,'*'); //        const char * REPORT_FILE = "C:\\tmProfile.txt"; FILE * fp = fopen(REPORT_FILE,"w"); if(!fp) { printf("\n<<>>:       (%s)",REPORT_FILE); return; } fprintf(fp,"\n#%s",bar.c_str()); fprintf(fp,"\n#\n#      "); fprintf(fp,"\n#\n#%s",bar.c_str()); fprintf(fp,"\n#\n# %-35s %-15s %-20s", " ",""," ()"); fprintf(fp,"\n# %-35s %-15s %-20s", "------------------","-------------","---------------\n#"); //         std::sort(entries.begin(),entries.end(),cmp_entries); for(unsigned jj = 0; jj< entries.size(); jj++) { fprintf(fp,"\n# %-35s %-16d", entries[jj].entry_name.c_str(), entries[jj].covers_counter); if(entries[jj].covers_counter == 0) fprintf(fp,"%-20d",0); else fprintf(fp,"%-20.0f", static_cast<double>(entries[jj].elapsed_time)/ static_cast<double>(CLOCKS_PER_SEC)); } if(entries.size() == 0) fprintf(fp,"\n# No covered profile entries found\n"); fprintf(fp,"\n#\n#%s\n",bar.c_str()); fclose(fp); } 

A estrutura do aplicativo de demonstração é ilustrada abaixo, ilustrando o uso das ferramentas de controle de tempo de execução integradas como exemplo, bem como uma tabela dos resultados obtidos (para obter detalhes, consulte o Apêndice 1. Código-fonte do aplicativo de demonstração ).





Adendo à Seção 2. O código fonte das ferramentas de controle internas para o tempo de execução do aplicativo C # apresenta uma implementação semelhante das ferramentas de controle internas em C #.

O autor usa pares de TimeWatcher.StartWatch () e TimeWatcher.StopWatch () ao determinar o tempo de execução de laboriosos (do ponto de vista computacional) métodos e procedimentos como parte do produto de software Delta Design desenvolvido pela EREMEX - um sistema de design auxiliado por computador para equipamentos eletrônicos.

Abaixo está um exemplo de um breve relatório sobre as métricas de tempo de uma das funcionalidades do produto mencionado.


Breves conclusões


As ferramentas descritas podem ser usadas para coletar dados sobre o tempo de execução do aplicativo em várias partes do código do programa, em particular, elas permitem:

  • coletar e acumular dados sobre métricas de tempo de threads de execução no aplicativo;
  • executar estimativas do tempo de execução do código do programa precisas para construções de linguagem elementar;
  • gerenciar o volume de dados extraídos ativando e desativando as ferramentas de controle integradas nas seções correspondentes dos fluxos de execução do aplicativo;
  • desenvolver e aplicar testes de regressão que monitoram a estabilidade (e detectam a degradação) das métricas de tempo do aplicativo.

Em conclusão, deve-se notar que fora do escopo desta publicação, havia questões sobre a aplicação das ferramentas de controle internas descritas no contexto de aplicativos multithreading e nenhuma análise da precisão dos dados obtidos por métricas de tempo foi apresentada de qualquer forma. Este último se deve ao fato de que, na prática, ao identificar as causas da degradação temporária de um aplicativo, os dados sobre a distribuição relativa dos custos de tempo de execução entre os componentes de software do aplicativo são principalmente relevantes . Nesse sentido, questões sobre a precisão dos dados obtidos estão desaparecendo em segundo plano.

Apêndice 1. Código Fonte para o Aplicativo Demo


 INITIALIZE_PROFILER int main(int argc, char * argv[]) { //create profile manager CREATE_PROFILER PROFILE_ENTRY("1 Main context") f11(); for(unsigned jj = 0;jj<4;jj++) f12(); f13 (); f14 (); f15 (); f16 (); f17(); return 0; } void f11(void)///////////////////////////////////////// { PROFILE_ENTRY ("2 f11()........................") for (unsigned jj = 0; jj<5; jj++) { PROFILE_ENTRY ("2 f11()::for(...){...} iterat-ing") DELAY(1) } //profile entry for repeating int nn(3); while(nn > 0) { PROFILE_ENTRY("2 f11()::while(...){...} iterat-ing") DELAY(1) nn--; } } void f12(void)///////////////////////////////////////// { PROFILE_ENTRY("3 f12()........................") goto ending; { PROFILE_ENTRY("3 f12()::ignored code part") DELAY(1) } ending: PROFILE_ENTRY("3 f12()::ending code part") DELAY(2) } void f13(void) ///////////////////////////////////////// { PROFILE_ENTRY("4 f13()........................") srand((unsigned) time(NULL)/2); for(unsigned jj = 0; jj < 200; jj++) { if(rand()%2 == 0) { PROFILE_ENTRY("4 f13()::even branch") DELAY(0.01) } else { PROFILE_ENTRY("4 f13()::od branch") DELAY(0.02) } } } void f14(void)///////////////////////////////////////// { static int depth = 10; { PROFILE_ENTRY("5 f14() recursion") depth--; DELAY(0.5) if(depth == 0) return; } f14(); } void f15(void)///////////////////////////////////////// { PROFILE_ENTRY("7 f15()........................") for(unsigned jj = 0; jj < 10; jj++) { demo_class obj; obj.method1(); obj.method2(); obj.method3(); } } void f16(void)///////////////////////////////////////// { PROFILE_ENTRY("8 f16()........................") try { for(int jj = 10; jj >= 0; jj--) { PROFILE_ENTRY("81 f16() try clause") DELAY(1) int rr = 200/jj; } } catch(...) { PROFILE_ENTRY("81 f16() catch clause") DELAY(2) return; } } void f17(void)///////////////////////////////////////// { PROFILE_ENTRY("9 f17()........................") f21(); f22(); f23(); f24(); f25(); } void f22(void)///////////////////////////////////////// { PROFILE_ENTRY("91 f22()........................") DELAY(1) f221(); f222(); f223(); } void f23(void) {PROFILE_ENTRY("91 f23()") DELAY(1) } void f24(void) {PROFILE_ENTRY("91 f24()") DELAY(1) } void f25(void) {PROFILE_ENTRY("91 f25()") DELAY(1) } void f221(void) {PROFILE_ENTRY("91 f221()") DELAY(3) } void f222(void) {PROFILE_ENTRY("91 f222()") DELAY(4) } void f223(void) {PROFILE_ENTRY("91 f223()") DELAY(5) } 

Suplemento 2. Código-fonte de aplicativos C # de controle de tempo de execução integrados


 /// <summary> ///             /// </summary> public class TimeWatcher { /// <summary> ///            /// </summary> internal class TimeEntry { //     public Stopwatch timeWatch; //       public long elapsedTime; //  public TimeEntry() { timeWatch = new Stopwatch(); elapsedTime = 0; } } //       //    private static bool enableTimeWatcher = false; //            private static Dictionary<string, TimeEntry> entryDictionary = new Dictionary<string, TimeEntry>(); //         public static void StartWatch(string postfix = "") { if (!enableTimeWatcher) return; string entryName = GetCurrentMethod(); if (postfix != "") { entryName += postfix; } //    ,      //         if (!entryDictionary.ContainsKey(entryName)) { entryDictionary.Add(entryName, new TimeEntry()); entryDictionary[entryName].timeWatch.Start(); } else { if (entryDictionary[entryName].timeWatch.IsRunning) { throw new System.InvalidOperationException(":    '" + entryName + "'  ."); } else entryDictionary[entryName].timeWatch.Restart(); } } //        public static void StopWatch(string postfix = "") { if (!enableTimeWatcher) return; string entryName = GetCurrentMethod(); if (postfix != "") { entryName += postfix; } //    ,      if (!entryDictionary.ContainsKey(entryName)) { throw new System.InvalidOperationException(":     -    '" + entryName + "'."); } if (!entryDictionary[entryName].timeWatch.IsRunning) { throw new System.InvalidOperationException ":        '" + entryName + "'."); } entryDictionary[entryName].timeWatch.Stop(); entryDictionary[entryName].elapsedTime += entryDictionary[entryName].timeWatch.ElapsedMilliseconds; } //        //     public static void TimeWatchReport() { const string bar = "============================================="; if (!enableTimeWatcher) return; Console.WriteLine(""); Console.WriteLine(bar); Console.WriteLine("     (): "); Console.WriteLine(""); int maxLen = 0; foreach (var timeEntry in entryDictionary) { if(timeEntry.Key.Length > maxLen) maxLen = timeEntry.Key.Length; } maxLen++; string strFormat = "{0," + maxLen + "} ... {1,-10}"; foreach (var timeEntry in entryDictionary) { Console.WriteLine(strFormat, timeEntry.Key, timeEntry.Value.elapsedTime); } Console.WriteLine(bar); Console.WriteLine(""); entryDictionary.Clear(); enableTimeWatcher = false; } //          //      /tmw    //   public static void InitTimeWatch() { if (Environment.GetCommandLineArgs().Any(v => v == "/tmw")) { if (entryDictionary.Count > 0) { TimeWatchReport(); } entryDictionary.Clear(); enableTimeWatcher = true; } } //        private static string GetCurrentMethod() { StackTrace st = new StackTrace(); StackFrame sf = st.GetFrame(2); return sf.GetMethod().Name; } } 

Source: https://habr.com/ru/post/pt468403/


All Articles