shell_exec() fails to execute on IIS 10 server

[pedwik]

I get this error when trying to import a repository:
APPLICATION ERROR #plugin_SourceViewVC_run_svn
shell_exec() failed to execute Subversion.
Please use the "Back" button in your web browser to return to the previous page....

Setup:
OS: Window Server 2016 (VPS)
MantisBT version: 2.6
Database: Sql Server 2014 Express
PHP: 7.1.9

Settings made in Source plugin configuration UI:
SVN: Path to binary: C:\csvn\bin
SVN: Command Arguments: Empty
SVN: Trust All SSL certifcates: True
SVN: Use Windows Start : True (tried both)

[bright-tools]

Which SVN distribution/version are you using, please?

[bright-tools]

If my understanding's correct, it should be trying to execute c:\csvn\bin\svn help first of all when you try to import a repo. Could you try that from a command line & check what the output is? Also check that this is accessible by whatever user PHP is effectively executing as?

[pedwik]

Subversion version is 1.8.17 (installed with Collabnet)

[pedwik]

AFAIK, on IIS 10 the application pool identity is the effective "user". This is some sort of virtual account that cannot be used as the user-parameter in a runas (test) command.

[bright-tools]

Thanks. I can reproduce this, so I'll take a look.

[bright-tools]

@pedwik - Two issues seem to be at work here, one of which I believe needs a code change (pull request submitted just now), the other of which will need you to add an SVN command argument - see #81 (FYI created an empty directory & used this as the parameter to the arg).

[pedwik]

Since "svn.exe" is added in the code to the path (right?) "SVN: Path to binary" should be the physical path to the folder where svn.exe is located, for example C:\csvn\bin and not C:\csvn\bin\svn.exe. Is this correct? If so, maybe that should be documented shortly in the form.

Concerning the SVN command argument field, should I enter for example
"--config -dir c:\csvn\someEmptyFolder" ? The discussion in #81 is not that 100% clear to me on what the conclusions were.

[bright-tools]

"SVN: Path to binary" should indeed be the directory containing the binary, as you say. Unfortunately, without the fix I submitted, the configuration options are ignored. It's a simple change, though, so hopefully you can manually update your install?

Regarding the SVN arg, what you have looks to be analogous the what I used (though note that it's --config-dir not --config -dir).

Debugging of failed SVN invocations could do with some improvement, to be honest. I might take a look at that in the future. Let us know how you get on, anyway.

[pedwik]

I added the code change and after that the "shell_exec()" error disappeared. But nothing is imported, a new error message is "svn info returned invalid xml code"

[dregad]

one of which I believe needs a code change (pull request submitted just now

Just merged the PR into master. I've been planning to cut an official 2.1.0 release for some time, but other priorities keep getting in the way.

[dregad]

"SVN: Path to binary" should be the physical path to the folder where svn.exe is located, for example C:\csvn\bin and not C:\csvn\bin\svn.exe. Is this correct? If so, maybe that should be documented shortly in the form.

Documentation for this plugin is sorely lacking. Any contribution in this area would be greatly appreciated... something along the lines of the existing "configuring" guides, in https://github.com/mantisbt-plugins/source-integration/tree/master/docs

[dregad]

a new error message is "svn info returned invalid xml code"

Not sure if it helps, but have a look at #132 where user had the same error message and managed to find a solution to the problem.

[bright-tools]

I added the code change and after that the "shell_exec()" error disappeared. But nothing is imported, a new error message is "svn info returned invalid xml code"

I had feared as much. Unfortunately the plugin doesn't check for errors & tries to parse the string returned from the SVN command as if the command had succeeded. I'll try and improve the call such that it'll report the error string returned by SVN rather than the XML parse error.

[dregad]

@bright-tools thanks for following up.

improve the call such that it'll report the error string returned by SVN rather than the XML parse error.

To achieve that, it would be necessary to capture output from STDERR, which shell_exec() can't (unless the command includes a 2>&1 redirection, but that would require some parsing of the output). I think a better approach would be to refactor the code to use proc_open() instead.

[bright-tools]

@dregad

I think a better approach would be to refactor the code to use proc_open() instead.

That's my plan! I'm 1/2 way through but didn't manage to get it done yesterday. Will hopefully have something ready for test in the near future.

[dregad]

@bright-tools I fooled around with this last night, have a look at the work-in-progress branch https://github.com/dregad/source-integration/tree/svninfo, let me know your thoughts.

[bright-tools]

@dregad That's very similar to the route I was heading down, except that I was looking to remove all instances of shell_exec() and replace them with a call to a helper function to wrap proc_open() & deal with the error reporting centrally. Happy to continue with this or let you finish your work.

[dregad]

As mentioned before, I was just playing with this, and thought that it might be useful to you. Indeed a helper function would be a much better approach, so just carry on as you like, and send a PR when you feel it's ready for review/testing.
Cheers!

[bright-tools]

@pedwik If you try again using the latest snapshot of source-integration you should get details of the error rather than an XML parse error. Let us know how it works for you.

[dregad]

Closing this following resolution of #247

[pedwik]

With the #247 commit the error message is much more informative. In this case there was one problem with user credentials for the mantis account to svn (but these were correct originally, in the first post). The import still does not work though. I wonder if there is a requirement for shell-access and cmd.exe for some other user? If so , I have found no way to change the permissions to cmd.exe in IIS 10 (have even tried ICACLS but get an access denied even when running as admin when when new permission settings are applied to cmd.exe). Running, from a browser, the following script placed in a temporary folder in the MantisBT root folder, works fine and returns NT AUTHORTY\ISUR:

&1',$out,$exitcode); echo "
EXEC: ( exitcode : $exitcode )"; echo "

---

";
print_r($out);
echo "

"; ?>

Looking at the log below the logon user is Anonymous, this puzzles me.

I have installed MantisBT on the Windows server by putting all files in a folder, and then adding a virtual directory in IIS the points to that folder.

Current error message diplayed in the browser:
C:\PHP7\php-cgi.exe - The FastCGI process exceeded configured request timeout

Most likely causes (I have marked unlikely once as UNLIKELY since they should affect Mantis core too):
IIS received the request; however, an internal error occurred during the processing of the request. The root cause of this error depends on which module handles the request and what was happening in the worker process when this error occurred. - UNLIKELY
IIS was not able to access the web.config file for the Web site or application. This can occur if the NTFS permissions are set incorrectly. - UNLIKELY
IIS was not able to process configuration for the Web site or application.
The authenticated user does not have permission to use this DLL.
The request is mapped to a managed handler but the .NET Extensibility Feature is not installed. - UNLIKELY

Things you can try:
Ensure that the NTFS permissions for the web.config file are correct and allow access to the Web server's machine account.
Check the event logs to see if any additional information was logged.
Verify the permissions for the DLL.
Install the .NET Extensibility feature if the request is mapped to a managed handler.
Create a tracing rule to track failed requests for this HTTP status code. For more information about creating a tracing rule for failed requests, click here.

Detailed Error Information:
Module FastCgiModule
Notification ExecuteRequestHandler
Handler FastCGI
Error Code 0x80070102
Requested URL https://www.XXXXXXX:443/bugtrack/plugin.php?page=Source/repo_import_full&id=14
Physical Path C:\mantisbt\plugin.php
Logon Method Anonymous
Logon User Anonymous

More Information:
This error means that there was a problem while processing the request. The request was received by the Web server, but during processing a fatal error occurred, causing the 500 error.

[bright-tools]

If you're getting a timeout when you try the import it could be due to the time taken to retrieve the data from the repo ( #60 is an example of this, but for Git). Does the repo that you're trying to import have a lot of commits? You could try temporarily modifying the activityTimeout and requestTimout parameters for the FastCGI handler to give it more time to work.

[pedwik]

There are almost 19000 commits. 18000 of the commits have no bug-issue in the Mantis DB (we changed from Bugzilla little more than a year ago). Is it possible to select just a range of commits to import, and use that as starting point?

[pedwik]

I am strill struggling with this problem, and it fails also with a very small repo that has less than 200 commits. The only error message I get is a "500 - Internal server error" after a couple of minutes. There are no messages for this in the php error log file. Any tip on how to proceed?

[dregad]

I would suggest, considering that your later issue seems to be different than the one you initially submitted this thread for, and in the interest of keeping things organized, that you open a separate issue to track the new problem.

That being said, I'm afraid there's not much I can do to help, with my very limited knowledge of IIS. You can try to add trace/logging output to the script to find out what is happening.

[kabadi]

pedwik, did you ever resolve your issue of "500 - Internal server error"? I am now getting the same.

[pedwik]

No, I did not.

[kabadi]

Thanks for reply. I had the Import Latest Data work when I had a single change to import. Since I then put another 30 commits in my SVN and tried again to Import Latest Data, I get the time out and 500 - Internal Server Error.

I amended the activityTimeout and requestTimout parameters for the FastCGI handler to 1800 but the only effect that had was that it took 30 minutes to time out.

[bright-tools]

@kabadi, what access method are you using to connect to your SVN repository? e.g. SSH, HTTPS, HTTP, etc?

[kabadi]

I am using HTTPS

I've tried to follow through the code and it seems to be ok up to line 298 of SourceSVN.php

$t_svnlog_xml = $this->svn_run( "log -v -r $t_rev:HEAD --limit 200 $t_url --xml", $p_repo );

It seems to be at this point it just spins.

[bright-tools]

If you manually execute the command from a shell:

svn.exe log -v -r 0:HEAD --limit 200 https://repo/here --xml

Do you get a valid response (and within a reasonable time)? I found some old comments on one of the SVN mailing lists which suggest that some repos which contain commits including a large number of files can be very slow for some operations due to permissions checking. Might be a red herring, but worth checking out.

[kabadi]

Sorry I should have said, when debugging, I got the command that was being attempted and ran it from a shell. It was as you've posted except not from the 0 revision.

I got a valid response (the log of revisions between the latest revision and HEAD) and it was pretty much instant.

It doesn't make much sense. It works when run manually and the previous SVN command in the code (the SVN info) works fine.

[bright-tools]

@kabadi, my reading of the code indicates that for the initial import (I presume that this is the stage which you're stuck at), it will attempt to start at revision 0, so is it possible to try from the shell again starting at this revision? If it is a server-end slow down then I understand that it would be quite dependent on the revision range requested (and what was done within those commits)

Are you also using PHP 7?

Sorry for all the questions - just trying to make sure that we're looking in the right place. From the PHP mailing lists it looks like there have historically been quite a few problems with proc_open but most of them look to have been addressed. If it turns out that the problem does lie there then we could possibly put a switch in to use the exec approach & see if this helps.

[kabadi]

No it isn't an initial import. I had migrated an existing mantisbt installation from another server.

Yes, PHP7.

Anyway, I found that this is likely an issue with proc_open and the handling of pipes. Furthermore, I found if I swapped the order in which each pipe was read and closed such that stdout was done first, then all the problems went away.

Changes in pull request #261

[bright-tools]

The ordering of the calls to the pipe reads will likely be sensitive depending on whether or not there is content in stderr and stdout. I suspect that simply reversing the calls fixes it for this situation but will fail under others.

[kabadi]

You may be right. For me though, it is preferable that it does not hang when there is no error. Possibly it might now hang if there is a lot of content (>2000+ chars) in stderr, but how likely is that?

Entirely up to you though if you take my change or not :-)

[bright-tools]

@kabadi, Thanks for taking the time to look at & debug the issue, that's appreciated. At least now we can be relatively certain where the problem is.

If I understand correctly, by reading one stream first, if there is >stream_buffer_size of bytes waiting on the other stream, the script will hang, as the call to stream_get_contents() will be blocking on an empty stream and the process will be stuck waiting on something to read the other stream before continuing to execute, hence deadlock.

I see now what you mean about the ~2k chars on stderr (which would be needed to cause a read to an empty stdout stream to block indefinitely).

We can't robustly use set_stream_blocking() in order to allow non-blocking reads to stream_get_contents() as I was originally looking at, but some experimentation suggests that we can use a combination of stream_select() and fstat() to work out which streams have data ready to read. It works for a simplistic test case on Windows PHP where the previous code blocks.

@dregad, I'd suggest that #261 is better that what is there currently even if it does still have a corner case which will could be addressed in the longer term.

[dregad]

I'd suggest that #261 is better that what is there currently even if it does still have a corner case which will could be addressed in the longer term.

You mean the 2nd commit, swapping the order in which the pipes are read from stderr, stdout to stdout, stderr ?

[obmsch]

I ran into this problem the first time yesterday. I am running a post-commit hook (POST to checkin.php)
and this was an unusual large commit (xml-size ~140KB). The script deadlocked until the servers timeout
kicked in (~15min) and killed it (Win10/1709-x64, IIS10, PHP7.1/x64, SourceIntegration 2.1.0, SVN 1.9.7).

Assuming STDERR will never exceed BUFFERSIZE (unlikely but possible), reversing the order the pipes are
read in SourceSVN.php should work and does for me. As this is a workaround and no "real solution", an
appropriate comment should be applied.

		# Get output of the process & clean up
		# Due to limitations (at least on windows) for the buffering of
		# pipes and possible resulting deadlocks the order the pipes are
		# read is crucial. The reordering (STDOUT before STDERR) will not(!)
		# prevent a deadlock, if the output of the subprocess to STDERR
		# exceeds the max buffered size on STDERR.
		$t_svn_out = stream_get_contents( $t_pipes[1] );
		fclose( $t_pipes[1] );
		$t_stderr = stream_get_contents( $t_pipes[2] );
		fclose( $t_pipes[2] );

Martin