The Case of The Unquoted Command Line: Process Monitor and MPGO.EXE
The Case of The Unquoted Command Line: Process Monitor and MPGO.EXE
Join the DZone community and get the full member experience.
Join For FreeA few months ago I wrote about MPGO, a new Microsoft tool that ships with .NET 4.5 and enables profile-guided optimization of managed assemblies. Specifically, MPGO optimizes the layout of native images for managed assemblies, which reduces startup times, working set sizes, and page fault costs.
Shameless plug: Pro .NET Performance has a large section dedicated to improving startup performance, and I’ve written about this before: Using Prefetch to improve startup performance, Rebasing and compression.
Anyway, I was experimenting with MPGO and encountered a strange error when working with some of my assemblies. Specifically:
C:\Temp\mpgo test>mpgo -scenario App.exe -assemblylist App.exe -OutDir . Error: Timeout or error when trying to instrument assembly C:\Temp\mpgo test\App.exe (FFFFFFFF) Profile information will not be collected for this assembly. This will not prevent information from being collected for other assemblies Error: Timeout or Error when trying to remove instrumented assembly C:\Temp\mpgo test\App.exe (FFFFFFFF) Failed to merge collected profile data into assembly C:\Temp\mpgo test\App.exe: Unexpected Internal Exception The file "C:\Temp\mpgo test\App.ibc" does not exist
This error struck me as odd, because the application in question was really simple, and I certainly didn’t know what error FFFFFFFF meant. I tried specifying the full path to the executable, and got a different error instead:
C:\Temp\mpgo test>mpgo -scenario "C:\temp\mpgo test\App.exe" -assemblylist "C:\temp\mpgo test\App.exe" -OutDir . Session executable does not appear to exist.
This produced a somewhat simpler error, although still completely misleading because App.exe exists in the specified directory. However, because the full path changed MPGO’s behavior, I suspected that something in its file access code or command-line parsing has gone awry.
This is where I launched Process Monitor and configured it to watch all events generated by MPGO.EXE. When using the latter command line, I saw very quickly that MPGO was trying (and failing) to access “C:\Temp\mpgo”, which is a directory that doesn’t exist—I explicitly gave it “C:\Temp\mpgo test\App.exe” as a parameter!
At this point I just had to look at the call stack to see what’s going on. MPGO.EXE is a managed application, but Process Monitor can’t give you managed call stacks (yet?), so I had to attach WinDbg and !u the raw addresses to see where the file access was coming from.
0:000> !u 0x600f8b Normal JIT generated code MPGO.Harness.PreRunValidation() Begin 00600e10, size 22d 00600e10 55 push ebp 00600e11 8bec mov ebp,esp …snipped… 00600f7e 8b4e04 mov ecx,dword ptr [esi+4] 00600f81 ba01000000 mov edx,1 00600f86 e8051e7f59 call mscorlib_ni+0x2f2d90 (59df2d90) (System.IO.File.InternalExistsHelper(System.String, Boolean), mdToken: 06004402) 00600f8b 85c0 test eax,eax 00600f8d 7541 jne 00600fd0 00600f8f b9fc432a00 mov ecx,2A43FCh (MT: MPGO.MpgoException) 00600f94 e88310c9ff call 0029201c (JitHelp: CORINFO_HELP_NEWSFAST) …snipped…
Next, I turned to the PreRunValidation method in Reflector and discovered that the exception is thrown because MPGO thinks my executable file does not exist, from a line that looks like this:
if (!File.Exists(this.Exe)) { MpgoException.Throw("Err_ExeMissing"); }
By inspecting all assignments to this.Exe, I found the following in the Harness class constructor:
Match match = Regex.Match(args[i], "(?<exe>(?:\"[^\"]+\")|[^ ]+)(?: (?<args>.*))?"); if (!match.Success) { Usage.Show("Err_CantParseScenario_0", args[i]); } this.Exe = match.Groups["exe"].ToString(); if (this.Exe.StartsWith("\"")) { this.Exe = this.Exe.Trim(new char[] { '"' }); } this.Exe = Path.GetFullPath(this.Exe); this.Args = match.Groups["args"].ToString();
When applied to a quoted path, such as “C:\temp\mpgo test\App.exe”, this code produces an unquoted executable name and considers everything that follows the space to be the executable’s arguments…
There is a different bug when using the former command line. In that case, I configured Process Monitor to log process (and thread) creation/deletion events, and noticed that MPGO.EXE launches NGEN.EXE with an invalid command line:
The full command line is:
"C:\Windows\Microsoft.NET\Framework\v4.0.30319\ngen.exe" install C:\Temp\mpgo test\App.exe /tuning /ExeConfig:C:\Temp\mpgo test\App.exe
…which confuses NGEN, because it treats “C:\Temp\mpgo” as the application name and the rest is an invalid command line. This time, the problem is that when launching NGEN, MPGO does not bother to quote the application name.
To summarize: the purpose of this post is not to bash MPGO—the bug has been reported to the team responsible and will likely be fixed in the next Visual Studio 11 drop. What I wanted to show is that Process Monitor is quite useful in determining why applications you aren’t familiar with are behaving incorrectly. Also, figuring out proper quoting of command line parameters is really nasty (on Windows).
Opinions expressed by DZone contributors are their own.
{{ parent.title || parent.header.title}}
{{ parent.tldr }}
{{ parent.linkDescription }}
{{ parent.urlSource.name }}