none
Printing strings at irql greater than passive_level RRS feed

  • Question

  • I have a printing method which I need to use at any irql and is as below

    typdefe struct _pinfo_

    {

    va_list list;

    PCHAR format;

    PIO_WORKITEM workitem;

    volatile ULONG isdone;

    }pinfo;

    void PrintInfo(PCCH format,...)

    {

    If(KeGetCurrentIrql>PASSIVE_LEVEL)

    {

    pinfo info;

    pinfo.workitem=IoAllocateworkitem(gdev);

    if(pinfo.workitem==NULL)

    {

    return;

    }

    pinfo.format=format;

    va_list args;

    va_start(args,format);

    pinfo.list=args;

    pinfo.isdone=1;

    ioqueueworkitem(pinfo.workitem,PrintRoutine,CriticalWorkQueue,&pinfo);

    while(1==InterlockedCompareExchange(pinfo.isdone,3,1);

    {

    }

    }

    PrintRoutine(DEVICE_OBJECT * dev,PVOID Context);

    {

    Unreferenced_param(dev);

    pinfo * print=(pinfo*)Context;

    Char buf[260];

    Nstatus stat=RtlStringCchPrintfA(buf,260,pinfo->format,pinfo->list);

    InterlockedIncrement(pinfo->isdone);

    IoFreeWorkItem(pinfo->workitem);

    //process buf further.

    }

    I have put a while loop so that the args and format are not destroyed before routine prints. Now I want to know it's if advisable to call printinfo at dispatch_level I'm just worried that especially if it takes long for the queued data to be sent to the print routine. What time does it take to call the print routine after adding item into the queue.Can it take long sometimes and does it affect performance.

    Another way was to allocate format and va_list but unfortunately va_list can not be allocated. Any idea on how to allocate va_list.

    Thursday, April 27, 2017 5:57 AM

Answers

  • You can't have a spin busy loop at high irql. If you don't insert a string, you can printf at high irql. Better yet, use wpp or etw logging and you can insert whatever you want at any irql

    d -- This posting is provided "AS IS" with no warranties, and confers no rights.


    Thursday, April 27, 2017 6:23 AM

All replies

  • You can't have a spin busy loop at high irql. If you don't insert a string, you can printf at high irql. Better yet, use wpp or etw logging and you can insert whatever you want at any irql

    d -- This posting is provided "AS IS" with no warranties, and confers no rights.


    Thursday, April 27, 2017 6:23 AM
  • Are they any other besides the string which cannot be printed at high irql. What if the string is allocated in a nonpaged pool does it cause a bug
    Thursday, April 27, 2017 1:21 PM
  • As Doron wrote, WPP or ETW can log anything at dispatch irql.

    The only issue with strings and IRQL is that DbgPrint converts wide strings to narrow, and it uses for this unicode  tables, located in pageable memory. If you do not print wide strings (or "unicode" strings) or call something like RtlUnicodeStringToAnsiString, and your strings are non-paged, it should be ok at dispatch irql. ETW and WPP work because they store the strings as is, without conversion.

    -- pa



    • Edited by Pavel A Thursday, April 27, 2017 11:38 PM
    Thursday, April 27, 2017 11:38 PM
  • Actually, that isn't quite true. WPP (which sits on top of ETW) does not log strings. Instead, it logs message codes and parameters. The definitions for these strings are stored in the .PDB file, and are fetched from there by whichever program (WinDBG, TraceView, etc.) is displaying the trace. This is part of why WPP/ETW is so fast and efficient; it logs very little data. The other major reason why it is efficient is that if there isn't a listener running, then WPP/ETW logging is virtually no cost.

     -Brian


    Azius Developer Training www.azius.com Windows device driver, internals, security, & forensics training and consulting. Blog at www.azius.com/blog

    Friday, April 28, 2017 12:23 AM
    Moderator
  • Actually, that isn't quite true. WPP (which sits on top of ETW) does not log strings. Instead, it logs message codes and parameters.

    Ok, so when a parameter is a wide string, it gets copies as raw data, not doing any troublesome rendering.

    If the kernel debugger protocol in the new Windows version had first class support for wide text , like in Windows CE (I do not know.. they did quite a few changes there) this limitation would be raised.

    -- pa


    • Edited by Pavel A Friday, April 28, 2017 8:34 PM
    Friday, April 28, 2017 8:29 PM
  • Yes, but passing strings (ANSI or Unicode) as parameters to a WPP message should to be minimized, if possible. You can drastically reduce the need to pass strings as parameters by defining your own custom WPP types to have WPP print out the names of enums:

    // In some header file:
    
    enum TLV_TYPE : DWORD
     {
     tlv_type_undefined = 0,
     tlv_type_request,
     tlv_type_
     tlv_type_notification,
     tlv_type_last
    };
    
    //In your WPP config file:
    
    // begin_wpp config
    // CUSTOM_TYPE (TLV_TYPES, ItemEnum (TLV_TYPE));
    // end_wpp
    
    // In your program/DLL/driver:
    
    TRACE_INFO (FILE_TLV, "Type: %!TLV_TYPES!, Length %d", tlv->type, tlv->length);
    
    The above will output the full name of the enum that defines the value. For outputting NTSTATUS values, use %!STATUS! and it will output the status name and value

     -Brian


    Azius Developer Training www.azius.com Windows device driver, internals, security, & forensics training and consulting. Blog at www.azius.com/blog

    Friday, April 28, 2017 8:44 PM
    Moderator