0

I have a simple app running on Windows Server 2012 using IIS. It is used to run an R script underneath (it's a very complicated script and rewritting it in Python is not an option). This is the code:

try:
    output = subprocess.run(cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE, encoding='utf-8')
except:
    return jsonify({'output': 'Error!', 'returncode': '0', 'error': 'Unknown Error'})
else:
    error = str(output.stderr)
return jsonify({'output': str(output.stdout), 'returncode': str(output.returncode), 'error': error})

It is ran by AJAX and is running fine most of the time, but sometimes it results in "Internal Server Error".

Now the interesting part. Above error is not caught by the except clause, it's not logged in the Flask error.log and the underlying R script does everything it's meant to do. So in short everything works as it should but it throws Internal Server Error for no particular reason. This is very annoying as the user gets an error despite everything working fine.

I already tried not using try/except and also "except Exception as err" but they also don't log any errors.

This is how error.log is setup. It works for other parts of the application without any issues.

app = Flask(__name__, static_url_path="", static_folder="static")    
errHandler = logging.FileHandler('errors.log')
errHandler.setLevel(logging.ERROR)
app.logger.addHandler(errHandler)

Any ideas how can I catch this error so I can try to debug it?

UPDATE

I've noticed that the Internal Server Error is returned after around 1.5 min. When I changed R script to a simple wait 10s command it works flawlessly so it seems to be a timeout issue.

I have set timeout to 180s on subprocess and ajax but it didn't help. Is there any other place I should look?

UPDATE 2

I've taken out ajax out of the equation and use standard hyperlink to the page with subprocess. It still gives Internal Server Error after 1.5 min. I've also changed R script to wait 2 min and the script itself finishes without any issues (30s after I get the error).

Damian Russak
  • 438
  • 5
  • 9
  • try to change the `else` to `finally` and check if it output anything. – Ami Hollander Dec 17 '18 at 14:07
  • I changed `else` to `finally` and the result is the same. Code in finally is not being run. It's like `subprocess` crashes so badly that it doesn't return to Python at all. – Damian Russak Dec 17 '18 at 15:50
  • seems like the subprocess fails and not handled due to the Operation System. consider looking for subprocess crash handling on windows – Ami Hollander Dec 17 '18 at 16:11
  • I noticed that the Internal Server Error is displayed after around 1.5 min every time. I've changed the R script in subprocess to only wait 2min and then save a file and it works without any issues. The problem seems to be on the subprocess part as it doesn't return to Python. I've set timeout to 180s in subrocess and ajax but this didn't have any effect. – Damian Russak Dec 18 '18 at 10:36

1 Answers1

0

I was looking in a completely wrong place. The issue was caused by the FastCGI Activity Timeout setting in IIS Manager. The timeout was only 70s while the subprocess took much longer to process. Increasing the Activity Timeout resolved the issue.

Damian Russak
  • 438
  • 5
  • 9
  • 1
    You may want to take a different approach. Instead of waiting for the subprocess you could just start it when the user triggers it. Then the user can check back later whether the subprocess has finished or not. – Wombatz Dec 20 '18 at 10:07
  • Good idea! Any tips of how to check if the subprocess finished? Another Ajax request? – Damian Russak Dec 21 '18 at 10:31
  • To check if the process is completed see [this question](https://stackoverflow.com/questions/43274476/is-there-a-way-to-check-if-a-subprocess-is-still-running). How you notify the user is up to you, ajax could work. – Wombatz Dec 21 '18 at 14:23