0

Quick version: In my project I have a command line tool that takes screenshots of all windows on the computer (bug collection tool for testing our product). This is part of a command line CollectSystemLogs.exe which collects many things, screenshots just being one item.

I have a small UI (CollectUSLogs.exe) that let's the tester/user select which items they want to select. It's just a UI front end, with CollectSystemLogs.exe command line doing all the real work (with parameters to tell it what to collect).

I can run the command line CollectSystemLogs.exe from a command line and all screenshots are collected just fine.

However, when I run the UI tool, CollectUSLogs.exe, and select screenshots, it only grabs a few and then seems to hang or something. It's stopping and I can't figure out why. Unfortunately, because it's a process started by the UI, I can't debug into it and if I ran just the command line, it works.

Relevant code:

This is the code for collecting the screenshots (please ignore all the verbose logging.....doing old school printf debugging).

/// <summary>Gets images of each window on the screen.</summary>
public static void CaptureWindows(string savePath)
{
    LogManager.LogDebugMessage($"Starting CaptureWindows({savePath})");
    AutomationElementCollection desktopChildren = AutomationElement.RootElement.FindAll(TreeScope.Children, Condition.TrueCondition);
    int windowCount = 1;

    LogManager.LogDebugMessage($"{desktopChildren.Count} desktopChildren (windows) found.");

    foreach (AutomationElement window in desktopChildren)
    {
        LogManager.LogDebugMessageConsole($"Capturing window [{window.Current.Name}]");


        Rect rect = window.Current.BoundingRectangle;
        if (Double.IsInfinity(rect.Width) || Double.IsInfinity(rect.Height))
        {
            LogManager.LogErrorMessageConsole($"[{window.Current.Name}] has at leat one infinite dimension.");
            LogManager.LogErrorMessageConsole($"w: {rect.Width}, h: {rect.Height}");
        }

        try
        {
            // TODO: Get rid of unneeded debug log prints
            LogManager.LogDebugMessage("In try{}");
            using (var bitmap = new Bitmap((int)rect.Width, (int)rect.Height))
            {
                LogManager.LogDebugMessage($"Bitmap Created {(int)rect.Width}x{(int)rect.Height}");
                using (Graphics graphic = Graphics.FromImage(bitmap))
                {
                    LogManager.LogDebugMessage($"Graphics created {graphic.ToString()}");
                    IntPtr handleDeviceContext = graphic.GetHdc();
                    var hwnd = (IntPtr)window.Current.NativeWindowHandle;
                    LogManager.LogDebugMessage($"hwnd created {hwnd.ToString()}");
                    if (hwnd == IntPtr.Zero) break;
                    NativeMethods.PrintWindow(hwnd, handleDeviceContext, 0);
                    LogManager.LogDebugMessage("PrintWindow() complete.");
                    graphic.ReleaseHdc(handleDeviceContext);
                }

                // Create File Name for image to be saved
                string fileName = Path.Combine(savePath, windowCount++.ToString("Window00") + ".png");
                LogManager.LogDebugMessage($"Saving {fileName}");
                bitmap.Save(fileName, ImageFormat.Png);
                LogManager.LogDebugMessage($"{fileName} saved");
            }
            LogManager.LogDebugMessage("End of try{}");
        }
        catch (Exception e)
        {
            LogManager.LogExceptionMessageConsole(e);
        }
        LogManager.LogDebugMessage("End of foreach");
    }
    LogManager.LogDebugMessage("Exiting CaptureWindows()");
}

I'm calling the command line with this:

if (!ProcessHelpers.RunCommandProcessCollectOutput(command, args, out output))
{
    MessageBox.Show($"Error running command line tool to collect system logs. Please save {Path.Combine(LogManagerConstants.LogFilePath,LogManagerConstants.LogFileBasename)} for analysis.", 
                @"CollectSystemLogs.exe Execution Error", MessageBoxButtons.OK,
                MessageBoxIcon.Exclamation);
}

And that code is here:

public static bool RunCommandProcessCollectOutput(string command, string args, out string output)
{
    // cmd arg /c => run shell and then exit
    // cmd arg /d => disables running of autorun commands from reg 
        //               (may inject extra text into output that could affect parsing)
    string localArgs = $"/d /c {command} {args}";
    string localCommand = @"cmd";

    if (command.StartsWith(@"\\"))
    {
        NetworkHelpers.CreateMapPath(Path.GetDirectoryName(command));
    }

    ProcessStartInfo procStartInfo = new ProcessStartInfo(localCommand, localArgs);

    procStartInfo.UseShellExecute = false; // use shell (command window)
    procStartInfo.CreateNoWindow = false; // Yes, create a window
    procStartInfo.ErrorDialog = false; // Will not show error dialog if process can't start
    procStartInfo.WindowStyle = ProcessWindowStyle.Normal; // Normal type window
    procStartInfo.RedirectStandardOutput = true; // redirect stdout so we can capture
    procStartInfo.RedirectStandardError = true; // redirect stderr so we can capture

    return _RunProcessCollectOutput(procStartInfo, out output);
}

The final piece:

private static bool _RunProcessCollectOutput(ProcessStartInfo procStartInfo, out string output)
{
    bool successful = true;
    output = ""; // init before starting
    LogManager.LogDebugMessage("_RunProcessCollectOutput");
    try
    {
        // Create proc, assign ProcessStartInfo to the proc and start it
        Process proc = new Process();
        proc.StartInfo = procStartInfo;

        // if collecting output, we must wait for process to end in order
        // to collect output.
        LogManager.LogDebugMessage($"Starting {procStartInfo.FileName} {procStartInfo.Arguments}");
        LogManager.LogDebugMessage("[wait forever]");

        successful = proc.Start();

        string temp1 = proc.StandardOutput.ReadToEnd(); // return output if any
        string temp2 = proc.StandardError.ReadToEnd(); // return error output if any

        proc.WaitForExit(); // Wait forever (or until process ends)

        if (temp1.Length > 0)
        {
            output += "[STDOUT]\n" + temp1 + "[/STDOUT]\n";
        }
        if (temp2.Length > 0)
        {
            successful = false;
            output += "[STDERR]\n" + temp2 + "[/STDERR]\n";
        }
    }
    catch (Exception e)
    {
        if (procStartInfo != null)
        {
            LogManager.LogErrorMessage($"Error starting the process {procStartInfo.FileName} {procStartInfo.Arguments}");
        }
        LogManager.LogExceptionMessage(e);
        successful = false;
    }

    return successful;
}

So, as I said...it works fine when I run from the command line, but when that command is called from within the UI this way it seems to only get the first few windows and then hangs.

See that output from log. It gets the first few (which appear to be the taskbars on the three monitors I have, then it just hangs. It appears to just stop after the fourth even though it tells me:

40 desktopChildren (windows) found.

I'm guessing the cmd window in the fourth is the one that is running the tool, but I don't see how that should matter.

[20190116164608|DBG|CollectUSLogs.exe]_RunProcessCollectOutput
[20190116164608|DBG|CollectUSLogs.exe]Starting cmd /d /c C:\XTT\UsbRoot\bin\CollectSystemLogs.exe  -ss -dp D:\
[20190116164608|DBG|CollectUSLogs.exe][wait forever]
[20190116164608|DBG|CollectSystemLogs.exe]Argument: -ss 
[20190116164608|DBG|CollectSystemLogs.exe]Argument: -dp 
[20190116164608|DBG|CollectSystemLogs.exe]D:\
[20190116164608|ERR|CollectSystemLogs.exe]Could not find a part of the path 'e:\host\config\iu\systemoptions.xml'.
[20190116164608|ERR|CollectSystemLogs.exe]   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRigh
[20190116164608|ERR|CollectSystemLogs.exe]ts, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Bo
[20190116164608|ERR|CollectSystemLogs.exe]olean bFromProxy, Boolean useLongPath, Boolean checkHost)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 buffe
[20190116164608|ERR|CollectSystemLogs.exe]rSize)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.XmlDownloadManager.GetStream(Uri uri, ICredentials credentials, IWebProxy proxy, RequestCac
[20190116164608|ERR|CollectSystemLogs.exe]hePolicy cachePolicy)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.XmlUrlResolver.GetEntity(Uri absoluteUri, String role, Type ofObjectToReturn)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.XmlTextReaderImpl.FinishInitUriString()
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.XmlTextReaderImpl..ctor(String uriStr, XmlReaderSettings settings, XmlParserContext context
[20190116164608|ERR|CollectSystemLogs.exe], XmlResolver uriResolver)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.XmlReaderSettings.CreateReader(String inputUri, XmlParserContext inputContext)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.XmlReader.Create(String inputUri, XmlReaderSettings settings, XmlParserContext inputContext
[20190116164608|ERR|CollectSystemLogs.exe])
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.Linq.XDocument.Load(String uri, LoadOptions options)
[20190116164608|ERR|CollectSystemLogs.exe]   at System.Xml.Linq.XDocument.Load(String uri)
[20190116164608|ERR|CollectSystemLogs.exe]   at XTT.USCartHelpers.get_SerialNumber() in C:\XTT\XTT_Tools\XTT\Helpers\USCartHelpers.cs:line 64
[20190116164608|ERR|CollectSystemLogs.exe]Cannot find Registry32 HKEY_LOCAL_MACHINE\SOFTWARE\WOW6432Node\Philips\PHC\Ultrasound
[20190116164608|WRN|CollectSystemLogs.exe]GetOptionalRegValue: Unable to find ProductModel.
[20190116164608|ERR|CollectSystemLogs.exe]Cannot find Registry32 HKEY_LOCAL_MACHINE\SOFTWARE\WOW6432Node\Philips\PHC\Ultrasound
[20190116164608|WRN|CollectSystemLogs.exe]GetOptionalRegValue: Unable to find ProductProgram.
[20190116164608|DBG|CollectSystemLogs.exe]Zipfilename: D:\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND).zip
[20190116164608|DBG|CollectSystemLogs.exe]ZipFolder = C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)
[20190116164608|WRN|CollectSystemLogs.exe]Can't empty C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND). It doesn't exist.
[20190116164608|INF|CollectSystemLogs.exe]C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND) created
[20190116164608|ERR|CollectSystemLogs.exe]Can't copy SystemOption*.xml in e:\host\config\iu. It doesn't exist.
[20190116164608|ERR|CollectSystemLogs.exe]ERROR collecting SystemOptions.
[20190116164608|ERR|CollectSystemLogs.exe]SystemOptions may not be included in zip file.
[20190116164609|DBG|CollectSystemLogs.exe]Starting CaptureWindows(C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND))
[20190116164624|DBG|CollectSystemLogs.exe]40 desktopChildren (windows) found.
[20190116164624|DBG|CollectSystemLogs.exe]Capturing window []
[20190116164624|DBG|CollectSystemLogs.exe]In try{}
[20190116164624|DBG|CollectSystemLogs.exe]Bitmap Created 1920x40
[20190116164624|DBG|CollectSystemLogs.exe]Graphics created System.Drawing.Graphics
[20190116164624|DBG|CollectSystemLogs.exe]hwnd created 2626768
[20190116164624|DBG|CollectSystemLogs.exe]PrintWindow() complete.
[20190116164624|DBG|CollectSystemLogs.exe]Saving C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window01.png
[20190116164624|DBG|CollectSystemLogs.exe]C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window01.png saved
[20190116164624|DBG|CollectSystemLogs.exe]End of try{}
[20190116164624|DBG|CollectSystemLogs.exe]End of foreach
[20190116164624|DBG|CollectSystemLogs.exe]Capturing window []
[20190116164624|DBG|CollectSystemLogs.exe]In try{}
[20190116164624|DBG|CollectSystemLogs.exe]Bitmap Created 1080x40
[20190116164624|DBG|CollectSystemLogs.exe]Graphics created System.Drawing.Graphics
[20190116164624|DBG|CollectSystemLogs.exe]hwnd created 66184
[20190116164624|DBG|CollectSystemLogs.exe]PrintWindow() complete.
[20190116164624|DBG|CollectSystemLogs.exe]Saving C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window02.png
[20190116164624|DBG|CollectSystemLogs.exe]C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window02.png saved
[20190116164624|DBG|CollectSystemLogs.exe]End of try{}
[20190116164624|DBG|CollectSystemLogs.exe]End of foreach
[20190116164624|DBG|CollectSystemLogs.exe]Capturing window []
[20190116164624|DBG|CollectSystemLogs.exe]In try{}
[20190116164624|DBG|CollectSystemLogs.exe]Bitmap Created 1920x40
[20190116164624|DBG|CollectSystemLogs.exe]Graphics created System.Drawing.Graphics
[20190116164624|DBG|CollectSystemLogs.exe]hwnd created 333194
[20190116164624|DBG|CollectSystemLogs.exe]PrintWindow() complete.
[20190116164624|DBG|CollectSystemLogs.exe]Saving C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window03.png
[20190116164624|DBG|CollectSystemLogs.exe]C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window03.png saved
[20190116164624|DBG|CollectSystemLogs.exe]End of try{}
[20190116164624|DBG|CollectSystemLogs.exe]End of foreach
[20190116164624|DBG|CollectSystemLogs.exe]Capturing window [C:\WINDOWS\SYSTEM32\cmd.exe]
[20190116164624|DBG|CollectSystemLogs.exe]In try{}
[20190116164624|DBG|CollectSystemLogs.exe]Bitmap Created 993x519
[20190116164624|DBG|CollectSystemLogs.exe]Graphics created System.Drawing.Graphics
[20190116164624|DBG|CollectSystemLogs.exe]hwnd created 269574
[20190116164624|DBG|CollectSystemLogs.exe]PrintWindow() complete.
[20190116164624|DBG|CollectSystemLogs.exe]Saving C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window04.png
[20190116164624|DBG|CollectSystemLogs.exe]C:\temp\20190116164608_TestCart00_(NOTFOUND)_(NOTFOUND)\Window04.png saved
[20190116164624|DBG|CollectSystemLogs.exe]End of try{}
[20190116164624|DBG|CollectSystemLogs.exe]End of foreach

Any ideas or suggestion would be much appreciated.

I've created a dummy command line that calls the same command line (CollectSystemLogs.exe) and it works using the same method call RunCommandProcessCollectOutput().

Adam Plocher
  • 13,994
  • 6
  • 46
  • 79
kingtermite
  • 55
  • 2
  • 9
  • Just curious, if you have UseShellExecute set to true does it make any difference? Edit: or `UseErrorDialog` set to true? – Adam Plocher Jan 17 '19 at 01:23
  • I had tried that...but apparently it doesn't let you have UseShellExecute true if you are using the Redirects on the output streams. – kingtermite Jan 17 '19 at 01:28
  • Is this a elevated privilege issue maybe – TheGeneral Jan 17 '19 at 01:41
  • I was thinking the same thing. Does your UI app have a manifest file, but your console app not (or vice versa)? Not sure if this is relevant to you, but it's a question I asked a couple years back regarding the uiAccess flag in the manifest which can potentially allow you to utilize (and override) various low-level UI's in the OS (start menu, task bar, even login window i think) https://stackoverflow.com/questions/35671903/considerations-when-installing-a-desktop-wpf-app-with-uiaccess-true Also, can you setup your logger to figure out what window 5 is? Or is 4 the problem you think? – Adam Plocher Jan 17 '19 at 02:32
  • Note, to even test the uiAccess flag you'll need to install a trusted self-signed cert (or get certified from MS), and the exe must exist in Program Files folders. There's a couple other requirements, deploying a legit app (certified from MS) didn't appear to be a simple task, but you can test it yourself with your own cert. – Adam Plocher Jan 17 '19 at 02:34
  • Another thing to check, is to open up Details tab in Task Manager and enable just about every column there is (right click on the column headers and select "Select columns"). Study the two exe's and see if anything permission'y differs considerably. ProcExplorer, ProcMonitor(both are freeware from SysInternals) and Resource Monitor (comes with Windows) may tell you a lot also. – Adam Plocher Jan 17 '19 at 02:39
  • I did try running as admin, didn't seem to make difference. I'm not using a manifest file, and really hope not to. – kingtermite Jan 17 '19 at 15:45
  • I did try SysInternals Process Explorer, but didn't think about ProcMon. I'll try that too. Thx. – kingtermite Jan 17 '19 at 15:46
  • OK. Solved. Not necessarily the way I 'wanted' to solve it, but it's solved enough to move forward. You were right the first time when you asked about the UseShellExecute. I had set to true, but got an error because I was trying to redirect stdout and stderr. I WANTED to redirect stdout and stderr, but you can't do that with UseShellExecute=true. So I never actually did run that way (thought I had, but apparently not). I used my other wrapper that runs with UseShellExecute=true and it works fine. I just don't get my stdout and stderr text in my log, but I log verbosely enough. – kingtermite Jan 17 '19 at 21:18

1 Answers1

0

OK...It turns out that @Adam Plocher was correct in first guess. It is the UseShellExecute flag.

I was using my wrapper for staring process which had UseShellExecute=false because that was required in order to redirect STDOUT and STDERR which I wanted in order to put them in my log.

I thought I had tried with UseShellExecute=true before, but I think when I tried that I got an error because it was still trying to redirect those streams and I must have stopped there.

I used my other wrapper which has UseShellExecute=true, but doesn't give me STDOUT and STDERR and it works. I guess I can live with that as do verbose logging enough in my code anyway.

I still don't know WHY it behaves that way when running process with UseShellExecute=false;

kingtermite
  • 55
  • 2
  • 9