Improve strace to log most Windows debug events

Not sure if this is wanted, but on a couple of occasions recently I have been
presented with strace output which contains an exception at an address in an
unknown module (i.e. not in the cygwin DLL or the main executable), so here is a
patch which adds some more information, including DLL load addresses, to help
interpret such straces.

v2:
Use NtQueryObject() for HANDLE -> filename conversion
Add new '-e' option to toggle this additional logging

2015-06-07  Jon Turney  <jon.turney@dronecode.org.uk>

	* strace.cc (proc_child): Log process and thread create and exit,
	and DLL load and unload.
	(GetFileNameFromHandle): New function.

Signed-off-by: Jon TURNEY <jon.turney@dronecode.org.uk>
This commit is contained in:
Jon TURNEY 2015-05-16 15:19:59 +01:00
parent 5979b17401
commit 5c4129d937
3 changed files with 80 additions and 2 deletions

View File

@ -2002,6 +2002,7 @@ Trace system calls and signals
-b, --buffer-size=SIZE set size of output file buffer
-d, --no-delta don't display the delta-t microsecond timestamp
-e, --events log all Windows DEBUG_EVENTS (toggle - default true)
-f, --trace-children trace child processes (toggle - default true)
-h, --help output usage information and exit
-m, --mask=MASK set message filter mask

View File

@ -1,3 +1,9 @@
2015-06-07 Jon Turney <jon.turney@dronecode.org.uk>
* strace.cc (proc_child): Log process and thread create and exit,
and DLL load and unload.
(GetFileNameFromHandle): New function.
2015-06-10 Corinna Vinschen <corinna@vinschen.de>
* ps.cc (main): Widen UID field in long format to accommodate longer

View File

@ -40,6 +40,7 @@ static int forkdebug = 1;
static int numerror = 1;
static int show_usecs = 1;
static int delta = 1;
static int events = 1;
static int hhmmss;
static int bufsize;
static int new_window;
@ -54,6 +55,8 @@ static BOOL close_handle (HANDLE h, DWORD ok);
#define CloseHandle(h) close_handle(h, 0)
static void *drive_map;
struct child_list
{
DWORD id;
@ -637,6 +640,30 @@ handle_output_debug_string (DWORD id, LPVOID p, unsigned mask, FILE *ofile)
fflush (ofile);
}
static BOOL
GetFileNameFromHandle(HANDLE hFile, WCHAR pszFilename[MAX_PATH+1])
{
BOOL result = FALSE;
ULONG len = 0;
OBJECT_NAME_INFORMATION *ntfn = (OBJECT_NAME_INFORMATION *) alloca (65536);
NTSTATUS status = NtQueryObject (hFile, ObjectNameInformation,
ntfn, 65536, &len);
if (NT_SUCCESS (status))
{
PWCHAR win32path = ntfn->Name.Buffer;
win32path[ntfn->Name.Length / sizeof (WCHAR)] = L'\0';
/* NtQueryObject returns a native NT path. (Try to) convert to Win32. */
if (drive_map)
win32path = (PWCHAR) cygwin_internal (CW_MAP_DRIVE_MAP, drive_map,
win32path);
pszFilename[0] = L'\0';
wcsncat (pszFilename, win32path, MAX_PATH);
result = TRUE;
}
return result;
}
static DWORD
proc_child (unsigned mask, FILE *ofile, pid_t pid)
{
@ -670,19 +697,42 @@ proc_child (unsigned mask, FILE *ofile, pid_t pid)
switch (ev.dwDebugEventCode)
{
case CREATE_PROCESS_DEBUG_EVENT:
if (events)
fprintf (ofile, "--- Process %lu created\n", ev.dwProcessId);
if (ev.u.CreateProcessInfo.hFile)
CloseHandle (ev.u.CreateProcessInfo.hFile);
add_child (ev.dwProcessId, ev.u.CreateProcessInfo.hProcess);
break;
case CREATE_THREAD_DEBUG_EVENT:
if (events)
fprintf (ofile, "--- Process %lu thread %lu created\n",
ev.dwProcessId, ev.dwThreadId);
break;
case LOAD_DLL_DEBUG_EVENT:
if (events)
{
// lpImageName is not always populated, so find the filename for
// hFile instead
WCHAR dllname[MAX_PATH+1];
if (!GetFileNameFromHandle(ev.u.LoadDll.hFile, dllname))
wcscpy(dllname, L"(unknown)");
fprintf (ofile, "--- Process %lu loaded %ls at %p\n",
ev.dwProcessId, dllname, ev.u.LoadDll.lpBaseOfDll);
}
if (ev.u.LoadDll.hFile)
CloseHandle (ev.u.LoadDll.hFile);
break;
case UNLOAD_DLL_DEBUG_EVENT:
if (events)
fprintf (ofile, "--- Process %lu unloaded DLL at %p\n",
ev.dwProcessId, ev.u.UnloadDll.lpBaseOfDll);
break;
case OUTPUT_DEBUG_STRING_EVENT:
handle_output_debug_string (ev.dwProcessId,
ev.u.DebugString.lpDebugStringData,
@ -690,9 +740,19 @@ proc_child (unsigned mask, FILE *ofile, pid_t pid)
break;
case EXIT_PROCESS_DEBUG_EVENT:
if (events)
fprintf (ofile, "--- Process %lu exited with status 0x%lx\n",
ev.dwProcessId, ev.u.ExitProcess.dwExitCode);
res = ev.u.ExitProcess.dwExitCode;
remove_child (ev.dwProcessId);
break;
case EXIT_THREAD_DEBUG_EVENT:
if (events)
fprintf (ofile, "--- Process %lu thread %lu exited with status 0x%lx\n",
ev.dwProcessId, ev.dwThreadId, ev.u.ExitThread.dwExitCode);
break;
case EXCEPTION_DEBUG_EVENT:
if (ev.u.Exception.ExceptionRecord.ExceptionCode
!= (DWORD) STATUS_BREAKPOINT)
@ -873,6 +933,7 @@ Trace system calls and signals\n\
\n\
-b, --buffer-size=SIZE set size of output file buffer\n\
-d, --no-delta don't display the delta-t microsecond timestamp\n\
-e, --events log all Windows DEBUG_EVENTS (toggle - default true)\n\
-f, --trace-children trace child processes (toggle - default true)\n\
-h, --help output usage information and exit\n\
-m, --mask=MASK set message filter mask\n\
@ -928,6 +989,7 @@ Trace system calls and signals\n\
struct option longopts[] = {
{"buffer-size", required_argument, NULL, 'b'},
{"events", no_argument, NULL, 'e'},
{"help", no_argument, NULL, 'h'},
{"flush-period", required_argument, NULL, 'S'},
{"hex", no_argument, NULL, 'H'},
@ -946,7 +1008,7 @@ struct option longopts[] = {
{NULL, 0, NULL, 0}
};
static const char *const opts = "+b:dhHfm:no:p:qS:tTuVw";
static const char *const opts = "+b:dehHfm:no:p:qS:tTuVw";
static void
print_version ()
@ -994,6 +1056,9 @@ main (int argc, char **argv)
case 'd':
delta ^= 1;
break;
case 'e':
events ^= 1;
break;
case 'f':
forkdebug ^= 1;
break;
@ -1090,7 +1155,13 @@ character #%d.\n", optarg, (int) (endptr - optarg), endptr);
if (toggle)
dotoggle (pid);
else
ExitProcess (dostrace (mask, ofile, pid, argv + optind));
{
drive_map = (void *) cygwin_internal (CW_ALLOC_DRIVE_MAP);
DWORD ret = dostrace (mask, ofile, pid, argv + optind);
if (drive_map)
cygwin_internal (CW_FREE_DRIVE_MAP, drive_map);
ExitProcess (ret);
}
return 0;
}