Cannot parse a valid IP address.
The last blog post I wrote was around and issue with xConnect certs, but what led me to it was an investigation in to malfunctioning Goe-Location personalisation. This post is a continuation of that saga.
I have started to create a module that uses the max mind C# libraries, but when testing it, I have been only receiving the default location and a corresponding error in the logs.
10868 13:44:12 INFO The address 10.10.1.2 is not in the database, returning default WhoIs.
This error indicates that the IP address does not exist in the Max Mind database, 10.10.1.2 is in the local range so MaxMind can not map it to a location as you would expect, and you might be thinking "great what's the problem"? Well, this IP address (whose real identity is obfuscated ;) is one of the internal IPs of the Azure gateway, so no matter where traffic has originated from a default WhoIs is always the answer to a Geo IP lookup and all requests are being personalised using the fallback location, and there is our problem.
To try and trace what was going on I went back to the CreateVisits pipeline, in particular, the XForwardedFor processor, the XFF is a "de-facto standard" to glean the original requesters IP address. When a proxy forwards a request, it adds its IP to the XFF header, and when it finally hits the web server, the application can interpret the header getting the original clients IP address.
It is worth noting this can be abused for both good and malicious intent, as this header is accumulative, and the fact that the receiving proxy has no way to validate any of the existing IPs in the header, it just adds its own and moves on. Using a browser add on you can add this header to your request and spoof your originating IP address, this is great for testing, but I would not rely on it to enforce any legal obligations.
In the XForwardedFor processor there is an error I was seeing in the log file
2080 00:27:53 WARN Cannot parse a valid IP address from X-Forwarded-For header.
Log.Warn(string.Format("Cannot parse a valid IP address from {0} header.", (object) requestHttpHeader), (object) this);
I guess that is OK, but first I wanted to know how the interaction IP was set with 10.10.1.2, and this was only a matter of opening the predecessor of the XForwardedFor, InitializeWithRequestData.
args.Interaction.Ip = ip;
With that solved I moved back on to the issue at hand, why was I receiving this error? The error message was not much help, so I cracked open dotPeek again and look at what might cause Sitecore to log this.
try
{
ipAddress = IPAddress.Parse(ipFromHeader);
}
catch (FormatException ex)
{
Log.Warn(string.Format("Cannot parse a valid IP address from {0} header.", (object) requestHttpHeader), (object) this);
return;
}
The only conclusion was that there was a FormatException thrown in the IPAddress.Parse method, this was located in the XForwardedFor processor.
Sometimes I am disappointed with the code ate runs Sitecore, and this logging is one of those times; if only the string that caused this exception ended up in the log file, I would have saved my self a deployment to the staging environment. Non the less this was not the case, and it could be for privacy reasons GDPR comes to mind, in any event, I moved on and created a replacement processor with more verbose logging.
public override void Process(CreateVisitArgs args)
{
Assert.ArgumentNotNull((object)args, nameof(args));
var requestHttpHeader = AnalyticsSettings.ForwardedRequestHttpHeader;
if (string.IsNullOrEmpty(requestHttpHeader))
return;
var header = args.Request.Headers[requestHttpHeader];
Log.Debug($"{requestHttpHeader} header is {header}", this);
if (string.IsNullOrEmpty(header))
return;
var ipFromHeader = this.GetIpFromHeader(header);
if (string.IsNullOrEmpty(ipFromHeader))
{
Log.Warn($"Cannot get a valid IP address from {requestHttpHeader} header.", this);
}
else
{
IPAddress ipAddress;
try
{
ipAddress = IPAddress.Parse(ipFromHeader);
}
catch (FormatException ex)
{
Log.Error($"Cannot parse IP({ipFromHeader}) from {requestHttpHeader} header.", ex, this);
return;
}
args.Interaction.Ip = ipAddress.GetAddressBytes();
}
}
I pushed the replacement process to staging and received this nugget of information.
9144 16:30:30 INFO X-Forwarded-For header is 213.35.140.123:7987
9144 16:30:30 ERROR Cannot parse IP(213.35.140.123:7987) from X-Forwarded-For header.
A port in the XFF header?!, my first thought was to double check the specification to see it this was a legit entry, but because this is a "de-facto standard" it is.
Another one of my favorite tools is LINQPad, this little application is a great way to quickly scratch out ideas and test code with out firing up VisualStudio. I wanted to test out what was and was not valid input of IPAddress.Parse.
var ipaddresses = new string[]{
"192.168.1.1",
"192.168.1.1:59698",
"2001:0db8:85a3:0000:0000:8a2e:0370:7334",
"::1",
"::",
"2001:0db8:85a3::8a2e:0370:7334",
"2001:0db8::8a2e:0370:7334",
"2001:0db8::8a2e:0370:7334",
"[2001:0db8:85a3:0000:0000:8a2e:0370:7334]:59698"
};
foreach(var ip in ipaddresses)
{
try
{
var ipAddress = IPAddress.Parse(ip);
Console.WriteLine(ipAddress.ToString());
}
catch
{
Console.WriteLine($"Could not parse: {ip}");
}
}
Output:
192.168.1.1
Could not parse: 192.168.1.1:59698
2001:db8:85a3::8a2e:370:7334
::1
::
2001:db8:85a3::8a2e:370:7334
2001:db8::8a2e:370:7334
2001:db8::8a2e:370:7334
2001:db8:85a3::8a2e:370:7334
The above showed me that the inclusion of a port on an IP string was only an issue for IPv4 addresses, IPv6 parses with a port just fine. This made the algorithm to handle ports straight forward and allowed me to avoid a regular expression that could have introduced performance concerns.
var ipOnly = ip;
if(ip.Count(c => c == ':') == 1)
{
ipOnly = ip.Split(':')[0];
}
With the above four lines I updated my bespoke processor, and deployed it into the staging environment.
public class XForwardedFor : CreateVisitProcessor
{
public int HeaderIpIndex => 0;
public override void Process(CreateVisitArgs args)
{
Assert.ArgumentNotNull((object)args, nameof(args));
var requestHttpHeader = AnalyticsSettings.ForwardedRequestHttpHeader;
if (string.IsNullOrEmpty(requestHttpHeader))
return;
var header = args.Request.Headers[requestHttpHeader];
Log.Debug($"{requestHttpHeader} header is {header}", this);
if (string.IsNullOrEmpty(header))
return;
var ipFromHeader = this.GetIpFromHeader(header);
if (string.IsNullOrEmpty(ipFromHeader))
{
Log.Warn($"Cannot get a valid IP address from {requestHttpHeader} header.", this);
}
else
{
IPAddress ipAddress;
try
{
ipAddress = IPAddress.Parse(ipFromHeader);
}
catch (FormatException ex)
{
Log.Error($"Cannot parse IP({ipFromHeader}) from {requestHttpHeader} header.", ex, this);
return;
}
args.Interaction.Ip = ipAddress.GetAddressBytes();
}
}
protected virtual string GetIpFromHeader(string header)
{
Assert.ArgumentNotNull(header, nameof(header));
var strArray = header.Split(',');
var headerIpIndex = HeaderIpIndex;
var ip = headerIpIndex < strArray.Length ? strArray[headerIpIndex] : strArray.LastOrDefault();
if (ip != null && IsIpv4(ip))
{
ip = RemovePort(ip);
}
return string.IsNullOrEmpty(ip) ? null : ip.Trim();
}
private static bool IsIpv4(string ip) => NumberOfColons(ip) == 1;
private static string RemovePort(string ip) => ip.Split(':')[0];
private static int NumberOfColons(string ip) => ip.Count(c => c == ':');
}
The issue now seems to be solved, and if it does raise its ugly head again I will have information in the log files to help me debug it.
Before finishing up I wanted to give a shout out to Mikael Högberg and his blog post Sitecore X-Forwarded-For handling, I was not experiencing the interpretation of the XFF header in reverse that he was, maybe Sitecore has fixed this since he composed that post, but it helped speed up the debugging of the issue, thanks.