Long time to first byte for my Flask app homepage

Question

I have a Flask site deployed to IIS via wfastcgi configuration.

When I use chrome or firefox developer tools to analyse the loading time of the homepage, I find many seconds (ranging from 6 to 10 in average) as waiting time to receive the first byte.

It was even 30 seconds before, but then I "optimized" my python code to avoid any db sql operation at loading time. Then I've followed the hints of this blog of nspointers, and now from the taskbar of the server I see the w3wp.exe for my app pool identity

w3wp.exe – It is the IIS worker process for the application pool

staying up and running even during idle time. But that is not true for the other

python.exe – The main FastCGI process for the Django or flask applications.

and I'm not sure if this is a problem and just in case what I am supposed to do, aside from the step 4 described in the mentioned post.

Now in the “Edit FastCGI Application” dialog under “Process Model” edit the “Idle Timeout” and set it to 2592000 which is the max value for that field in seconds

I've also looked at the log written by the Flask app and compared it to the log written by IIS and this is the most important point in making me believe that the issue is in the wfastcgi part, before the execution of the python code.

Because I see that the time-taken of the IIS log matches with the client time reported by chrome or firefox as TTFB and the log written by python at the start of the execution is logged at almost the same time of the time written by IIS, that

corresponds to the time that the request finished

(as I thought indeed and as I find it's confirmed by this answer)

So in conclusion, based on what I tried and what I understand, I suspect that IIS is "wasting" many seconds to "prepare" the python wfascgi command, before actually starting to execute my app code to produce a response for the web request. It is really too much in my opinion, since other applications I've developed (for example in F# WebSharper) under IIS without this mechanism of wfastcgi load immediately in the browser and the difference in the response time between them and the python Flask app is quite noticeable. Is there anything else I can do to improve the response time?

Answer 1

Ok, now I have the proof I was searching and I know where the server is actually spending the time. So I've researched a bit about the wfastcgi and finally opened the script itself under venv\Lib\site-packages.

Skimming over the 900 lines, you can spot the relevant log part:

def log(txt):
    """Logs messages to a log file if WSGI_LOG env var is defined."""
    if APPINSIGHT_CLIENT:
        try:
            APPINSIGHT_CLIENT.track_event(txt)
        except:
            pass
    
    log_file = os.environ.get('WSGI_LOG')
    if log_file:
        with open(log_file, 'a+', encoding='utf-8') as f:
            txt = txt.replace('\r\n', '\n')
            f.write('%s: %s%s' % (datetime.datetime.now(), txt, '' if txt.endswith('\n') else '\n'))

Now, well knowing how to set the environment variables, I defined a specific WSGI_LOG path, and here we go, now I see those 5 seconds TTFB from chrome (as well as the same 5 seconds from IIS log with time 11:23:26 and time-taken 5312) in the wfastcgi.py log.

2021-02-01 12:23:21.452634: wfastcgi.py 3.0.0 initializing
2021-02-01 12:23:26.624620: wfastcgi.py 3.0.0 started

So, of course, wfastcgi.py is the script one would possibly try to optimize...

BTW, after digging into it, that time is due to importing the main flask app

handler = __import__(module_name, fromlist=[name_list[0][0]])

What remains to be verified is the behavior of rerunning the process (and the import of the main flask module, that is time consuming) for each request.

In conclusion, I guess it is a BUG, but I have solved it by deleting the "monitoring changes to file" FastCGI settings as per the screenshot below.

The response time is under a second.

Answer 2

I have a different answer to you by suggesting you try to switch over to HTTP Platform Handler for your IIS fronted Flask app.

Config Reference

This is also the recommended option by Microsoft:

Your app's web.config file instructs the IIS (7+) web server running on Windows about how it should handle Python requests through either HttpPlatform (recommended) or FastCGI.

https://learn.microsoft.com/en-us/visualstudio/python/configure-web-apps-for-iis-windows?view=vs-2019

Example config can be:

<configuration>
  <system.webServer>
    <handlers>
      <add name="httpplatformhandler" path="*" verb="*" modules="httpPlatformHandler" resourceType="Unspecified"/>
    </handlers>
    <httpPlatform processPath="c:\inetpub\wwwroot\run.cmd" 
                  arguments="%HTTP_PLATFORM_PORT%" 
                  stdoutLogEnabled="true" 
                  stdoutLogFile="c:\inetput\Logs\logfiles\python_app.log"
                  processPerApplication="2"
                  startupTimeLimit="60"
                  requestTimeout="00:01:05"
                  forwardWindowsAuthToken="True"
                  >
      <environmentVariables>
        <environmentVariable name="FLASK_RUN_PORT" value="%HTTP_PLATFORM_PORT%" />
      </environmentVariables>
    </httpPlatform>
  </system.webServer>
</configuration>

With run.cmd being something like

cd %~dp0
.venv\scripts\waitress-serve.exe --host=127.0.0.1 --port=%1 myapp:wsgifunc

Note that the HTTP Platform handler will dynamically set on a port and passing that into the python process via the FLASK_RUN_PORT env var which flask will automatically take as a port configuration.

Security notes:

• Make sure you bind your flask app to localhost only, so it's not visible directly from the outside - especially if you are using authentication via IIS
• In the above example the forwardWindowsAuthToken is being set which then can be used to rely on Windows Integrated authentication done by IIS then the token passed over to Python and you can get the authenticated user name from Python. I have documented that here. I actually use that for single-sign on with Kerberos and AD group based authorization, so it works really nice.

Example to only listen on localhost / loopback adapter to avoid external requests hitting the python app directly. In case you want all requests to go via IIS.

if __name__ == "__main__":
    app.run(host=127.0.0.1)