DriverEntry.com.br

Depois de alguns meses em um longo processo seletivo, finalmente já posso compartilhar essa boa notícia com vocês. Boa notícia para mim pelo menos. Hoje, dia 15 de outubro 2007 foi meu primeiro dia como IBMista no prédio da rua Tutóia. Não, eu não desisti do Kernel do Windows para programar Java nem vou programar ABAP. O negócio é o de sempre, tela azul mesmo.

Como você aprendeu isso?

Essa é uma pergunta que várias pessoas já me fizeram. Parece brincadeira, mas parece que as coisas têm contribuído naturalmente para o meu desenvolvimento profissional como programador Kernel para Windows. Quando eu era estagiário na Provectus, comecei a ler o livro "Desvendando o Windows NT" por puro hobby, sem a menor esperança de um dia poder trabalhar com as coisas abordadas por aquela literatura, afinal de contas, ter o privilégio de trabalhar em uma empresa de desenvolvimento de hardware no Brasil seria como ganhar na loteria. Bom, meu estágio como programador C foi em uma empresa que desenvolvia seu próprio hardware. Sorte talvez. Quando menos esperei, lá estava eu programando serviços para Windows NT, utilizando memória compartilhada e até um device driver apareceu pra eu dar uma olhada. Como eu já sabia alguma coisa de MFC e Win32 API, o que me atraía mesmo era o desenvolvimento em Kernel Mode. Mais uma vez por hobby, comecei a ler a respeito, sem esperanças devo dizer, apenas por prazer mesmo. É, desta vez o resultado foi contrário e fui trabalhar em uma empresa de compra e venda de ações da bolsa de valores para desenvolver compotentes COM+ em c++. Um ano foi o bastante para aprender o suficiente de ASP, SQL e Java para saber que não era aquilo que eu queria para mim. Felizmente o destino me trouxe a SCUA. Eu nem sabia que eles faziam drivers para Windows. Foi durante uma entrevista para fazer parte do time de aplicações que descobri que havia um time de drivers. Enfim, adivinha em qual time fui parar depois de um tempo. Lá tive contato com profissionais da área, muitos livros, listas de discussão e principalmente a oportunidade de por em prática o que eu aprendia nos livros. Depois veio a Tempest e com ela as chances de fazer um treinamento de File System Drivers em uma das maiores autoridades no assunto. Em seguida um amigo me indicou na IBM, e depois de duas entrevistas no prédio da rua Tutóia e uma entrevista técnica por telefone com o time dos Estados Unidos, bem aqui estou eu. Vou trabalhar no time de desenvolvimento do MVFS para Windows.

Um dos pontos que mais me anima nesta nova empreitada é a oportunidade de trabalhar com pessoas altamente qualificadas no assunto e poder aprender muito com um time que envolve minimamente americanos, indianos, e agora mais um brasileiro.

Meu primeiro dia de IBM foi cheio de palestras. Inicialmente sobre a história da IBM, e as outras foram mais sobre os vários procedimentos internos que uma empresa deste porte exige.

Inté mais...

Na primeira parte deste post, falei um pouco das necessidades e da lógica básica envolvida em criar e enviar mensagens para o log de eventos do sistema. Hoje vou extender um pouco mais falando sobre como enviar parâmetros nestes eventos, não ficando apenas preso às mensagens fixas definidas no arquivo .mc. Mais um driver de exemplo está disponível para download no final deste post.

Enviando parâmetros nas mensagens

Até agora vimos como se pode mandar strings fixas para o EventViewer, mas seria muito útil poder mandar strings geradas pelo driver. Seguindo com o assunto de tratamento de exceções, ao longo deste post escreveremos uma função que possa ser chamada do bloco __except e assim logar qual exceção foi lançada e manipulada pelo seu driver, assim o administrador finalmente vai ficar sabendo que algo errado está acontecendo. Se você não sabe do que estou falando, dê uma olhada na primeira parte deste post.

Como dizia Jack, o estripador: "Vamos por partes". Primeiro vamos fazer com que o código da exceção possa ser exibido no evento. Para isso teremos que colocar essa informação no pacote alocado. O membro DumpData da estrutura IO_ERROR_LOG_PACKET pode levar dados binários ao EventViewer. Este membro é um array de ULONG e tem seu tamanho variável definido pelo membro DumpDataSize, que deve ser sempre um múltiplo de sizeof(ULONG). Pensando em nosso exemplo, poderíamos colocar na primeira posição deste array o código da exceção que foi manipulada, tal como 0xC0000005 para "Access Violation". Veja o exemplo abaixo que adiciona essa funcionalidade. Lembre-se que além de setar o membro DumpDataSize adequadamente, os bytes utilizados pelos elementos deste array deveriam ser levados em consideração na hora de determinar o tamanho do pacote a ser alocado.

/****
***     SendHelloEventWithData
**
**      Função que aloca e envia um evento que
**      envia um parâmetro adicional de 32 bits.
*/
 
VOID SendHelloEventWithData(IN ULONG    ulData)
{
    PIO_ERROR_LOG_PACKET    pLogPacket;
 
    //-f--> Aloca a entrada para o evento. Devemos somar
    //      os bytes ultilizados no array DumpData. Este
    //      tamanho deve sempre se multiplo de sizeof(ULONG).

    pLogPacket = IoAllocateErrorLogEntry(pDriverObj,
                                         sizeof(IO_ERROR_LOG_PACKET) +
                                         sizeof(ULONG));
 
    //-f--> Inicializa toda a estrutura
    RtlZeroMemory(pLogPacket, sizeof(IO_ERROR_LOG_PACKET));
 
    //-f--> Coloca a mensagem desejada
    pLogPacket->ErrorCode = EVT_HELLO_MESSAGE;

 
    //-f--> Preenche o dump binário e seu respectivo tamanho
    pLogPacket->DumpData[0] = ulData;
    pLogPacket->DumpDataSize = sizeof(ULONG);
 
    //-f--> Envia a entrada para a lista de eventos
    IoWriteErrorLogEntry(pLogPacket);
}

Chamando esta função passando 0x12345678 como parâmetro, poderemos observar o dado enviado como mostra a figura abaixo.

Inserindo Strings

Mas onde essas strings vão aparecer no registro de eventos? Teremos que criar novas mensagens, que façam uso dessas strings, em nosso aquivo de mensagens. A partir daqui, construiremos uma rotina que será chamada dentro do bloco __except para logar a exceção que foi manipulada. Completem o arquivo de mensagens com o seguinte texto.

 
MessageId = 0x0002
Facility = DriverEntryLogs
Severity = Warning
SymbolicName = EVT_EXCEPTION_HANDLED_MESSAGE
 
Language = Portuguese
A casa caiu na rotina %2 com status %3.
.
Language = English
The house fell down at routine %2 with status %3.
.

Reparem que nas novas mensagens existem esses esquisitíssimos %2 e %3. Estes serão os pontos onde a primeira e segunda string serão inseridas respectivamente na mensagem. Mas por que a primeira string é indicada por %2 ao invés de %1? O indicador %1 é reservado para mapear uma string com o nome do driver ou do device. Isso vai depender de qual objeto foi passado no primeiro parâmetro da função IoAllocateErrorLogEntry. Embora %1 seja perfeitamente documentado, algumas vezes a string não é substituída na mensagem quando o driver está iniciando ou terminando. Não me perguntem por quê.

Para deixar nosso exemplo mais completo, seria muito útil se pudéssemos colocar uma string que carregasse o símbolo definido no header ntstatus.h. Assim teríamos STATUS_ACCESS_VIOLATION para a exceção de código 0xC0000005 no texto exibido pelo EventViewer.

O primeiro problema é transformar o código da exceção, que é um valor numérico, em uma string. Esse deve ter sido a necessidade de vários programadores Kernel, porque no site da OSR Online existe o fonte de uma funçãozinha que faz isso. Para se ter uma idéia, essa funçãozinha é implementada em aproximadamente 2200 linhas de código. Acha muito? Dê uma olhada no início dela e você entenderá.

PUCHAR OsrNTStatusToString(NTSTATUS Status) {
 
    switch (Status) {
    case STATUS_SUCCESS:
        return "STATUS_SUCCESS";
    case STATUS_WAIT_1:
        return "STATUS_WAIT_1";
    case STATUS_WAIT_2:
        return "STATUS_WAIT_2";
...

Depois disso, teremos que converter esta string de ANSI para unicode, mas está tudo no código de exemplo.

Para que as strings possam ser exibidas pelo event EventViewer, mesmo quando o driver não estiver carregado, estas precisam ser copiadas para dentro do pacote. Então agora é determinar qual o tamanho do pacote que vai ser alocado pela função IoAllocateErrorLogEntry. O tamanho do pacote deverá ser somado da quantidade de bytes ocupados pela string unicode incluindo o terminador zero. Acho que será melhor vocês acompanharem os comentários no fonte abaixo que já faz tudo.

/****
***     LogExceptionHandled
**
**      Recebe um NTSTATUS e envia um registro para
**      o log de eventos do sistema
*/
 
VOID LogExceptionHandled(PWSTR     wzFunctionName,
                         NTSTATUS  nts)
{
    UNICODE_STRING          usNtStatus;
    ANSI_STRING             asNtStatus;
    UCHAR                   ucFinalSize;
    PWSTR                   pwzTarget;
    PIO_ERROR_LOG_PACKET    pLogPacket;
 
    //-f--> Inicializa uma ANSI_STRING com o código do erro
    RtlInitAnsiString(&asNtStatus,
                      OsrNTStatusToString(nts));

 
    //-f--> Passa a string para unicode
    RtlAnsiStringToUnicodeString(&usNtStatus,
                                 &asNtStatus,
                                 TRUE);
 
    //-f--> Calcula o tamanho do pacote sendo respectivamente:
    //
    //  Tamanho da estrutura IO_ERROR_LOG_PACKET
    //  Tamanho do elemento que vai no DumpData
    //  Tamanho da string que conterá o código do erro

    //      lembrando que devemos reservar espaço paro terminador
    //  Tamanho da string com o nome da função que gerou a
    //      exceção mais o respectivo terminador (/0)
    ucFinalSize = sizeof(IO_ERROR_LOG_PACKET) +
                  sizeof(ULONG) +
                  usNtStatus.Length + sizeof(WCHAR) +
                  (wcslen(wzFunctionName) + 1) * sizeof(WCHAR);
 

    //-f--> Aloca a entrada para o evento
    pLogPacket = IoAllocateErrorLogEntry(g_pDriverObj,
                                         ucFinalSize);
 
    //-f--> Inicializa toda a estrutura
    RtlZeroMemory(pLogPacket, sizeof(IO_ERROR_LOG_PACKET));
 
    //-f--> Armazena o código de erro no array DumpData
    //      e indica seu tamanho no DumpDataSize
    pLogPacket->DumpData[0] = nts;
    pLogPacket->DumpDataSize = sizeof(ULONG);

 
    //-f--> Informa onde as strings começam e quantas são
    pLogPacket->StringOffset = sizeof(IO_ERROR_LOG_PACKET) +
                               pLogPacket->DumpDataSize;
    pLogPacket->NumberOfStrings = 2;
 
    //-f--> Copia a primeira string para dentro do pacote
    pwzTarget = (PWSTR) ((PCHAR)pLogPacket +
                                pLogPacket->StringOffset);
    wcscpy(pwzTarget,
           wzFunctionName);
 
    //-f--> copia a segunda string para dentro do pacote
    pwzTarget += wcslen(wzFunctionName) + 1;
    wcsncpy(pwzTarget,
            usNtStatus.Buffer,
            usNtStatus.Length / sizeof(WCHAR));

 
    //-f--> Como a não está escrito na documentação da
    //      RtlAnsiStringToUnicodeString que sempre haverá
    //      um zero ao final da string convertida, não podemos
    //      admitir que este esteja sempre lá.
    pwzTarget += usNtStatus.Length / sizeof(WCHAR);
    *pwzTarget = 0;
 
    //-f--> Coloca a mensagem desejada
    pLogPacket->ErrorCode = EVT_EXCEPTION_HANDLED_MESSAGE;

 
    //-f--> Envia a entrada para a lista de eventos
    IoWriteErrorLogEntry(pLogPacket);
 
    //-f--> Libera a string que foi convertida
    RtlFreeUnicodeString(&usNtStatus);
}

Dessa forma, o bloco __except da nossa função de exemplo, dada na primeira parte deste post, poderia ficar como mostra abaixo.

    ...
    __except(EXCEPTION_EXECUTE_HANDLER)
    {
        //-f--> Oops! Uma exceção foi lançada. Vamos logar isso,
        //      fingir demência e apenas retornar o código da exceção
        nts = GetExceptionCode();
 
        //-f--> Envia um registro para o log de sistema

        LogExceptionHandled(__FUNCTIONW__, nts);
        ASSERT(FALSE);
    }
    ...

Para testar, vamos fazer uma chamada para a função DupString passando parâmetros inválidos, tais como NULL, e obteremos a seguite saída exibida abaixo. Todo o código fonte do exemplo demonstrado está disponível para download no final deste post.

O fim está próximo

Como expliquei na primeira parte deste post, o registro do evento não vai para o disco sincronamente quando a função IoWriteErrorLogEntry é chamada, ao invés disso, o registro do evento vai para uma lista ligada antes de ir para disco. Caso a máquina caia e um dump seja gerado, podemos consultar essa lista com o comando !errlog no WinDbg que analiza o dump gerado. Legal, vamos ver se funciona mesmo? Vamos enviar a mensagem abaixo e em seguida deferenciar um ponteiro nulo, só pra... O código que faz isso está escrito na função KillYourSelf() no código de exemplo disponível para download.

 
MessageId = 0x0003
Facility = DriverEntryLogs
Severity = Error
SymbolicName = EVT_GOODBYE_MESSAGE
 
Language = Portuguese
Adeus mundo cruel!
.
Language = English
Goodbye cruel world!
.

A função KillYourSelf somente será chamada quando um determinado símbolo for definido como você pode ver abaixo. Portanto, se quiser fazer o teste e ver os resultados com seus próprios olhos, modifique a definição deste símbolo no início do código fonte e refaça o teste com uma máquina de teste.

 
#if _WHERE_IS_THE_PENGUIN_
    //-f--> Meu sonho era ser um driver de Linux
    KillYourSelf();
#endif

Inevitavelmente uma tela azul ocorrerá, e com ela um dump de memória será gerado. Abrindo este dump para análise usando o WinDbg, devemos chamar o comando !errlog para termos a saída como mostra abaixo.

Microsoft (R) Windows Debugger  Version 6.7.0005.0
Copyright (c) Microsoft Corporation. All rights reserved.
 
 
Loading Dump File [C:\Documents and Settings\froberto\Desktop\MEMORY.DMP]
Kernel Complete Dump File: Full address space is available
 
Symbol search path is: srv*c:\symbols*http://msdl.microsoft.com/download/symbols
Executable search path is: 
Windows 2000 Kernel Version 2195 UP Free x86 compatible
Product: WinNt
Kernel base = 0x80400000 PsLoadedModuleList = 0x8046a4c0
Debug session time: Thu Oct 11 11:05:56.375 2007 (GMT-3)
System Uptime: 0 days 0:02:06.875
Loading Kernel Symbols
.................................................................................................
Loading User Symbols
 
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************
 
Use !analyze -v to get detailed debugging information.

 
BugCheck 1E, {c0000005, be552682, 1, 0}
 
Probably caused by : EventSender.sys ( EventSender!KillYourSelf+2a )
 
Followup: MachineOwner
---------
 
kd> !errlog
PacketAdr  DeviceObj  DriverObj  Function  ErrorCode  UniqueVal  FinalStat
81551108   00000000   815c1830    0        402a0001   00000000   00000000
        \Driver\EventSender
        DumpData:  12345678 
815b1f88   00000000   815c1830    0        802a0002   00000000   00000000
        \Driver\EventSender
        DumpData:  c0000005 
81535248   00000000   815c1830    0        c02a0003   00000000   00000000
        \Driver\EventSender

Na coluna ErrorCode, temos os códigos que foram definidos pela compilação do arquivo de mensagens e que estão visíveis no arquivo de header que também foi gerado. Observe as mensagens e seus respectivos identificadores no trecho abaixo. Como pode-se notar, nenhuma das três mensagens de teste utilizadas neste exemplo foram para disco. Todos os registros ainda estavam em memória. Desta forma, não espere ver estas mensagens no EventViewer, elas ainda não foram gravadas em disco.

//
// MessageId: EVT_HELLO_MESSAGE
//
// MessageText:
//
//  Ola mundo!
//
#define EVT_HELLO_MESSAGE                ((NTSTATUS)0x402A0001L)

 
//
// MessageId: EVT_EXCEPTION_HANDLED_MESSAGE
//
// MessageText:
//
//  A casa caiu na rotina %2 com status %3.
//
#define EVT_EXCEPTION_HANDLED_MESSAGE    ((NTSTATUS)0x802A0002L)
 
//
// MessageId: EVT_GOODBYE_MESSAGE
//
// MessageText:
//

//  Adeus mundo cruel!
//
#define EVT_GOODBYE_MESSAGE              ((NTSTATUS)0xC02A0003L)

Ufa! Pensei que este post não fosse mais terminar. Mais uma vez espero ter ajudado e até mais.

Download EventSender.zip