Search code examples
url-rewrite-moduleiis-10iis-logs

Custom field in IIS log has "-" for value for certain Paths


I have configured the following rewrite rule in an ASP.NET application's "web.config" hosted on IIS:

    <rewrite>
        <rules>
            <rule name="setappname">
                <match url=".*" />
                <serverVariables>
                    <set name="CONTAINER_APP_NAME" value="desiredValue" />
                </serverVariables>
            </rule>
        </rules>
    </rewrite>

And in "applicationHost.config", I have the following snippets:

    <sites>
        <site name="mysite" id="1" serverAutoStart="true">
            <application path="/" applicationPool=".NET v4.5">
                <virtualDirectory path="/" physicalPath="c:\mysite" />
            </application>
            <bindings>
                <binding protocol="http" bindingInformation="*:80:" />
            </bindings>
            <logFile directory="c:\iislog" period="MaxSize" truncateSize="4294967295">
                <customFields>
                    <add logFieldName="x-forwarded-for" sourceName="X-Forwarded-For" sourceType="RequestHeader" />
                    <add logFieldName="container-app" sourceName="CONTAINER_APP_NAME" sourceType="ServerVariable" />
                </customFields>
            </logFile>
            <applicationDefaults preloadEnabled="true" />
        </site>
    </sites>

AND

<system.webServer>
    <rewrite>
        <allowedServerVariables>
            <add name="CONTAINER_APP_NAME" />
        </allowedServerVariables>
    </rewrite>
</system.webServer>

This works fine (I see the 2 custom fields in the logs) except when the Path ends with "/" (e.g.: / or /APath/). In those cases, the value of the container-app field (using Server Variable) is always "-". For instance:

$ curl --silent --output /dev/null -H "X-Forwarded-For:10.3.2.12" http://localhost/APath/

Yields:

2019-12-02 20:47:32 172.29.152.165 GET /APath/ - 80 - 192.168.7.4 curl/7.67.0 - 200 0 0 121 10.3.2.12,+::1 -

Whereas:

$ curl --silent --output /dev/null -H "X-Forwarded-For:10.3.2.12" http://localhost/home.aspx

Yields:

2019-12-02 20:50:17 172.29.152.165 GET /home.aspx - 80 - 192.168.7.4 curl/7.67.0 - 200 0 0 63 10.3.2.12,+::1 desiredValue

I even enabled the Failed Request Tracing to see if perhaps the rewrite rule isn't picking up those paths, but I can confirm that the rule matches the path and the server variable is set to the desired value.

I wonder if there is anything else I can try to troubleshoot this. Why such paths aren't logged properly?


Solution

  • I think I found the issue and posting it here for others.

    By looking at the Failed Request Traces, I can see that IIS creates child requests for directories' default documents (URIs ending with "/"). Apparently, by design, rewrite rules don't apply to child requests (e.g.: https://forums.iis.net/t/1152699.aspx).

    To solve this, I created a rewrite rule to change such requests to be explicit requests to documents so the other rewrite rule gets applied at the main process level:

           <rewrite>
                <rules>
                    <rule name="setExplictDoc">
                        <match url="(.*(APath)/$)" />
                        <action type="Rewrite" url="{R:0}Default.aspx" />
                    </rule>
                    <rule name="setappname">
                        <match url=".*" />
                        <serverVariables>
                            <set name="CONTAINER_APP_NAME" value="desiredValue" />
                        </serverVariables>
                    </rule>
                </rules>
            </rewrite>
    

    The idea came from https://support.microsoft.com/en-ca/help/3050055/iis-digest-authentication-does-not-permit-pass-though-authentication-f