topic Re: Why does Splunk "Show Source" not match IIS log file? in Getting Data In

Why does Splunk "Show Source" not match IIS log file?

pzhou07920 — Wed, 30 Sep 2020 02:25:25 GMT

Hi,

At my company, we have noticed that for some records (1-2%), the data we see in Splunk does not match the data coming from the IIS logs. This is a rather interesting problem, when we conducted research into the issue we noticed a very strange thing.

When you click "Show Source" on one of the bad records, we see what appears to be our IIS log records. However, when we actually look at the record closely, we noticed that the record is actually parts of 2 different records concatenated together. This is how our Splunk data looks compared to our IIS data.

I'm adding the field names above each field for clarity
Record shown in Splunk "Show Source"
Field1 Field2 Field3 Field4 Field5
AAAA BBBB CCCC DDbbb cccc

IIS Record matching first part of Splunk "Show Source" Record
Field1 Field2 Field3 Field4 Field5
AAAA BBBB CCCC DDDD EEEE

IIS Record matching second part of Splunk "Show Source" Record
Field1 Field2 Field3 Field4 Field5
aaaa bbbb cccc dddd eeee

As you can see, the record shown in Splunk's "Show Source" is actually parts of 2 records concatenated together. It takes the first part of one record, up to some arbitrary location (character length is not consistent, does not care about fields since it will split in the middle of a field value) and then takes the second part of some other record beginning from some arbitrary location and then concatenates them together. Splunk then indexes this new record but it is throwing our metrics off.

We first came across this issue when we noticed that there were some cases where multiple login Ids were associated with a single session ID...after drilling down we determined that was caused by this concatenation occurring on typically just one record where the session ID from one record is concatenated with another record that contains a different user ID.

Edit: Provided sample records with sensitive data redacted.

***Record in Splunk Show Source:* 2019-10-07 11:45:55 W3SVC21 {ServerName} XX.XX.XX.XXX GET {Api Endpoint} - 8183 - XX.XX.XX.XXX HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/XX.XX.XX.XXX+Safari/537.36 _gtmStorage={"nshpr":"1"};+_ga=GA1.2.476813979.1556711308;+optimizelyEndUserId=oeu1556711309110r0.2097434021739768;+_ju_dc=09ad39e0-6c07-11e9-8aca-998c75893382;+ELOQUA=GUID=93716A6025BC494DB6DD0C3E56D886FE;+s_fid=7B5BECFE2A9CCB31-027699913483E6D5;+ezLaborManager=CompanyID={CompanyId}&CompanyName={CompanyName}&Language=en-US;+elabor%2Ecom+Time=2=110996&1={CompanyName};+_pendo_accountId.87c4ca07-8cfa-42ee-43e2-619b249c619c=20929499;+{redacted};+k8Ksj346=AitrfJtsAQAAZCb8IijVcHoNAE1vlT0SoowioaCUv_n4JOxsJwAAAWybfGsrAWWfjoM|1|b65f46919231346680707fd503b5efad47a406e4;+_gcl_au=1.1.961302088.1569843670;+_fbp=fb.1.1569843670097.548616165;+_ju_dn=1;+C3UID-195=9157859991569843670;+C3UID=9157859991569843670;+iv=7b3d85e0-87d8-48ce-a052-2dd76678015f;+_gid=GA1.2.201089313.1570447739;+s_cc=true;+s_sq=%5B%5BB%5D%5D;+DomainUrl={DomainUrl};+BadPasswordUrl={BadPasswordUrl};+ASP.NET_SessionId=zkavtyg5hz0c5fy0izjc0k0f;+CSCID.Hybrid=0D35B2762BEE4EEE0599B07C7AA46245DAA51D6E521D42377FEA1B09781E7FDCC55DADFA694C5B58;+{redacted}=2434351115.63263.0000;+HELPURL=help%2fhelppage.aspx;+SUPPORTURL={SupportUrl};+{redacted};+_pendo_viFCe8ZzHHBKK+QYwRW2qqS/bplms7728oFWwcnZhRdk+iJ6EPdytZkfyhzFFH1R2fYnOYS9h5wq8HLcZaXz+tDVX//x3E7hJLf4oFJqX6uBrrEfkKETqAMWqHjHnTfvOPUxARPiHQ2gfwABM59pML0HXkTY3pOtCjjvHhC588pcEz1NugQgnv/cpINyejcHDeJiU/gJnwabJcOltSkk5oPGRV2kE2Eiw/Tkrmw+bZ9Ojg+fiZNqnxhPETfvBchzTGT4os+R6tUqVxKio0cpmEMMo6bEs07ixt7ZPWq2zveo7J66n7fTIv3qpb6tYtWosjBZtBRnu9UX2rgCGGL8hbee/fnfc68/dJn0zKYg5f+7acIKJumAbgIKquCbl/w13FLbhYBOzxGV1j28AIDLuGHIxf3RYMuqJWWx7jg1Q9l+bXqTdbBEvtDIfdguiLGhWW0cmN+DqDXUt1ULX8BhU7t0vnFTznjlDk5wBtYHjR/ZCemtyM3fEq0PpbdXpaR5J2eeekDBiP0tk6hK7aBwqUOZ4nMxqDfXnbYx3J3TZfAAA3LXbsrzzz9rwd14GufXHyMv/uWpEx6Vc16IeZWd6E7OLIpQKeU+XJU+gPAlY4nCeBkOm//sinyX2S+mtKDL1e3qq78z5z844s8nFS4VXF9BqGPygmm1kDusoX76dUn/HEYB/icByt2VVCV3pVN5ECNjFa2/ZQXrBIaxU9ZGCu80gH1UOHb4duMiR/N4wPlw++LrfAdilb4DXnIrqupB9MRBCg+eJ1A0LtAv6sHm2vOWtGO50D/C43EdpyEgsf1MzF6V {redacted} {redacted} 200 0 0 347 4301 0 XX.XX.XX.XXX,+XX.XX.XX.XXX uid={UID},ou=Users,o=23948293,ou=clients,o={home site} {UID} {AOID} {OOID}

***IIS Record matching First Part:*
Part 1 matches First part of Splunk Source: 2019-10-07 11:45:55 W3SVC21 {ServerName} XX.XX.XX.XXX GET {Api Endpoint} - 8183 - XX.XX.XX.XXX HTTP/1.1 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/77.0.3865.90+Safari/537.36 _gtmStorage={"nshpr":"1"};+_ga=GA1.2.476813979.1556711308;+optimizelyEndUserId=oeu1556711309110r0.2097434021739768;+_ju_dc=09ad39e0-6c07-11e9-8aca-998c75893382;+ELOQUA=GUID=93716A6025BC494DB6DD0C3E56D886FE;+s_fid=7B5BECFE2A9CCB31-027699913483E6D5;+ezLaborManager=CompanyID={CompanyId}&CompanyName={CompanyName}&Language=en-US;+elabor%2Ecom+Time=2=110996&1={CompanyName};+_pendo_accountId.87c4ca07-8cfa-42ee-43e2-619b249c619c=20929499;+{redacted};+k8Ksj346=AitrfJtsAQAAZCb8IijVcHoNAE1vlT0SoowioaCUv_n4JOxsJwAAAWybfGsrAWWfjoM|1|b65f46919231346680707fd503b5efad47a406e4;+_gcl_au=1.1.961302088.1569843670;+_fbp=fb.1.1569843670097.548616165;+_ju_dn=1;+C3UID-195=9157859991569843670;+C3UID=9157859991569843670;+iv=7b3d85e0-87d8-48ce-a052-2dd76678015f;+_gid=GA1.2.201089313.1570447739;+s_cc=true;+s_sq=%5B%5BB%5D%5D;+DomainUrl={DomainUrl};+BadPasswordUrl={BadPasswordUrl};+ASP.NET_SessionId=zkavtyg5hz0c5fy0izjc0k0f;+CSCID.Hybrid=0D35B2762BEE4EEE0599B07C7AA46245DAA51D6E521D42377FEA1B09781E7FDCC55DADFA694C5B58;+{redacted}=2434351115.63263.0000;+HELPURL=help%2fhelppage.aspx;+SUPPORTURL={SupportUrl};+{url};+_pendo_vi

Part 2 does not Match Splunk Source:
sitorId.87c4ca07-8cfa-42ee-43e2-619b249c619c=G37N1CBMZ78V70FG;+_pendo_meta.87c4ca07-8cfa-42ee-43e2-619b249c619c=3158154672;+{redacted}=4eaf22d2efe73f5ce3266fb8af2a5a0aeab8c74172a9d91823050b5c9410a0f4;+PAASVERSION=XX.XX.XX.XXX;+ezlmbreadcrumbrpt=1=%5esid%253d_slt_92f1bd624c874811651c489111d94f9b%2526bcl%253d1%2526svc%253dAdmin%2526dojo.preventCache%253d1570448368692%2526addIFrame%253d0%2526hdnWFMode%253d1%5e%2fezLaborManagerNet%2fUI4%2fReports%2fReportCategoryReports.aspx%5e0%5eNormal;+elSessionKey=elReferrerDomain={elReferrerDomain}=N&wm=1;+ezlmbreadcrumb=ezlmbreadcrumb=NG^Home^Home&ezlmbreadcrumbNG=NG^%2fTLMWeb%2fExceptions%2fMultipleExceptions^People+and+Process+-+Timecard+Exceptions;+elSessionInfo=IuOp5tqlJmNCFvTIsV9RsyWlffkJIr/byRA5lrQpG0M=BJsE+z1nUGIc1pavzCLMSgOQa68FHbHCQQwfI3RaQC0Pne8sQ/adnwi9sIhaZ50S+ytOd4hq4I+fMi+N9x5J3DGGGoQwv7aqry0KyPliKu0R3ufgInOJLVAWg6QJc0rvkbPxFOtF5Dv4QQERdhBRpHYZk33qe2PKzjnO30BFvcFWs8njF4A2TOWkSxhF/OKP+LVT3W9sAiSk+wJFRFWqk3QLohe/nYiDC6bGQxDTVV3K/RW8dFXrD2c+kzL9gO9JyeLpVxUfa8wmgjRBrizRUBgHLHEwiBGld2dpzwB2evCOnM7T7TNVn4Px/yS0clRLy4VKvW3QS+Y0aIcOB9gBbTLXQ94OH/X/+mARCvHDmB51FQa2FAinB8h6LOQM7lOE6g/xWhzVmBySUZqr2MGjzCT7yW69AKtFBdJf2k2TdfghbjszdfK2b0ED3uQJBovUynos5Ns8ypkOz9eK0ZYvXRYoXIqXFAdiA2NwCy38Fbk=;+ROOT={redacted};+_gat_gtag_UA_99833711_4=1;+SMSESSION=jq4L2ZNZ29QqUn6zlvc72Yj7ixXVKt0gdsQTOIW+FGra60hr+fG0TBYG3XJgItNLt9IGm6xJzY+e7dg68PqbxXeQOP6KK8Cgy04QKmZVaX/F2Tbp22sGGuGS1AD1gZh40jADJe2/AaVT2/6z6hs+2YX89NVvNY7+s59ft63gTyYris+FA8Ig7pM0ntGpPRwKjNKB3lnX9GsBaGGcWAFgq3FxuaRhdEWXZgi3qNMXjYXrhjxKrJg02ivV0ljLyZXc6i3gJGC6lNUp8owkX4Q8YorukfzDITJMYy2/mF2qcJT64S1o5RKtlul3HRYT3cpdSDCFk22FO/dOQgEIpG6wTqJnJaib6JYlsIg0vXVnx8yC8HeX6UCYWNHhkrsYTZaxGmCsRObjlHnVSyefrXPoTXhAwVOPqyfGEtpWC5UlUxNeUNU+Bwv6Phd6Y6R1WZWtfSHxXI6SSXu/f2SObxnW1kS5BKOakywYm2z+0Drna4bxpgwTjEDhOmY0Y0764PBpGP1UuXy/egWMI5u9yQ5nAqY111I2eVACeUFyGF4CBHTp7g5M1gp9CT/EjXlBwaqxzbzmNkbkDRU0ApZIR1V8SfxcLu+fpetFtddPrYVLW9HP4ky+wrx2TMsx7SQ8WF1imWApKXkc2OzwAG8dVsRNdcn0am/6ugSTxKpVY+jSiHes6IaHkxz2Bo6wv0165f/QVmjfn+ujrsFerefemUU11yfLzn8obEonErYwX/osaE5vG7Q6BbiyxSkyqIR/OQBRQ2/RSdI94+xegCI25KNkBXaGH1yGf3K79UTGkmmVhUJJ6MRKthsg3eQk7+FWHN1JvOyj4804N3mO9lNP0EwCY2UrnukNilyBAHjsszE56nRiWTYNZKqgEmTbeqCwSlfwPpedjBg8QSUdQ8dj3w3IivZRwyHV9rLrOsvuE+b0dRPwAJFxbgC5ytSUXrdB93pRmeuF4rDqsvomJbkpN2mve69anr1B1sp/52fCyU/tv/1AxeUfpqbVCI2fDJjT9GUTjcHvf2btUrhLzmm+GYVGUtIkSEtG/3x9fBXLfH1FXepIwyjzP0tzn7GZK+8Q095ZZQyoKDgecJW+g/Qp9NsQGXNPTnadQkXs2DKJWONU0qz7YC0R8GTNtrYlBqbyfiFiJgQ3xSg/XiBHzKaGeMHajRFTHT83jhPh {ApiEndpoint} {site} 200 0 0 5478 5961 0 XX.XX.XX.XXX,+XX.XX.XX.XXX uid={uid},ou=Users,o=20929499,ou=clients,o={home site} {UID} {AOID} {OOID}

IIS Record matching Second Part:
Part 1 does not Match Splunk Source: 2019-10-07 11:45:54 W3SVC21 {ServerName} XX.XX.XX.XXX GET {Api Endpoint} - 8183 - XX.XX.XX.XXX HTTP/1.1 Mozilla/5.0+(X11;+CrOS+x86_64+12371.75.1)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/77.0.3865.105+Safari/537.36 _ga=GA1.2.537143480.1568029346;+s_fid=0A55E88B05F55CCC-2AB08F7D98EEC9BB;+k8Ksj346=AocE1RVtAQAALk2AQvRKYdBQ9uuogcAcV0oNhRDjQkd5DbYYGwAAAW0V1QSHAa_ip98|1|7104800d7828e888f57331383b2647e2b6dfe7c4;+_pendo_accountId.87c4ca07-8cfa-42ee-43e2-619b249c619c=23948293;+_pendo_visitorId.87c4ca07-8cfa-42ee-43e2-619b249c619c=G3RS8GCN4M73HB9J;+_pendo_meta.87c4ca07-8cfa-42ee-43e2-619b249c619c=2881808332;+_gid=GA1.2.186691854.1570448737;+_gat_gtag_UA_99833711_4=1;+s_cc=true;+s_sq=%5B%5BB%5D%5D;+DomainUrl={DomainUrl};+BadPasswordUrl={BadPasswordUrl};+ASP.NET_SessionId=hjllio2lcut5bahva5zlgw0v;+CSCID.Hybrid=591BF16DA836EA1DCFF4E552DC47AAFD0D63F84C618CA930B7FA8A4758B4CCD2D43732D16881A33A;+{redacted}=2434351115.63263.0000;+ROOT={redacted};+HELPURL=help%2fhelppage.aspx;+SUPPORTURL={SupportUrl};+{redacted};+SMSESSION=wyPLXWxGf9BoLGLLaymeMTb/RN4GrZACoJ6/8aBRYlBYurhtu3S/vR3sNxuMfN7BFSLQk0if0a57Gwm3w0fzVpa9wW57nztVJHDK6rGW47MQCJY09VhzQEmXabaiX6s3pC6hhe/Zdl+tn9qH0EfuYSLeSbihPyFo8Mfq7joj/03CQxl0YWI3xAHIHfhpaiWTPojqB/QR0Euc5+uJe4ARDjXlbJ48NaLYh9h6Q86IEov6TVEL9LQ4e0CcO7oWElsq+B/5nkPEKDXcC/H69WRsZFMKcNaf49j7oD1WxbHUbTm7kpLVqluDc7+jBWj95qooYJO9v2NBeBTy1g1S20iv6ZfU+GdU4DOOWuQ9gUVrhnhD3KC6ds

Part 2 matches last part of Splunk Source: FCe8ZzHHBKK+QYwRW2qqS/bplms7728oFWwcnZhRdk+iJ6EPdytZkfyhzFFH1R2fYnOYS9h5wq8HLcZaXz+tDVX//x3E7hJLf4oFJqX6uBrrEfkKETqAMWqHjHnTfvOPUxARPiHQ2gfwABM59pML0HXkTY3pOtCjjvHhC588pcEz1NugQgnv/cpINyejcHDeJiU/gJnwabJcOltSkk5oPGRV2kE2Eiw/Tkrmw+bZ9Ojg+fiZNqnxhPETfvBchzTGT4os+R6tUqVxKio0cpmEMMo6bEs07ixt7ZPWq2zveo7J66n7fTIv3qpb6tYtWosjBZtBRnu9UX2rgCGGL8hbee/fnfc68/dJn0zKYg5f+7acIKJumAbgIKquCbl/w13FLbhYBOzxGV1j28AIDLuGHIxf3RYMuqJWWx7jg1Q9l+bXqTdbBEvtDIfdguiLGhWW0cmN+DqDXUt1ULX8BhU7t0vnFTznjlDk5wBtYHjR/ZCemtyM3fEq0PpbdXpaR5J2eeekDBiP0tk6hK7aBwqUOZ4nMxqDfXnbYx3J3TZfAAA3LXbsrzzz9rwd14GufXHyMv/uWpEx6Vc16IeZWd6E7OLIpQKeU+XJU+gPAlY4nCeBkOm//sinyX2S+mtKDL1e3qq78z5z844s8nFS4VXF9BqGPygmm1kDusoX76dUn/HEYB/icByt2VVCV3pVN5ECNjFa2/ZQXrBIaxU9ZGCu80gH1UOHb4duMiR/N4wPlw++LrfAdilb4DXnIrqupB9MRBCg+eJ1A0LtAv6sHm2vOWtGO50D/C43EdpyEgsf1MzF6V {Api Endpoint} {site} 200 0 0 347 4301 0 XX.XX.XX.XXX,+XX.XX.XX.XXX uid={uid},ou=Users,o=23948293,ou=clients,o={home site} {uid} {AOID} {OOID}

Re: Why does Splunk "Show Source" not match IIS log file?

gcusello — Thu, 10 Oct 2019 07:58:16 GMT

Hi pzhou07920,
to better understand this behaviour, you have to analyze how you ingested these data because there's surely a parsing error.
At first, do you used a TA from Splunk baseline or a custom one?

If you used a custom one, save an example of these logs with the wrong situation in a text file on your pc and then try to ingest it using the web gui [Settings -- Add Data], in this way you can debug your parsing and understand if there's an error.

If you could share an example containing both correct and wrong data, I could help you.

Bye.
Giuseppe

Re: Why does Splunk "Show Source" not match IIS log file?

pzhou07920 — Wed, 30 Sep 2020 02:26:03 GMT

My colleague told me this regarding the TA, "We are using the Splunk base line provided by SPLUNK and this is not part of TA". I have also updated the post with the log files related to one bad record. I included the record shown in "Show Source" as well as the 2 IIS records I determined to make up that one bad record.

in input.conf

[monitor://D:\IISLogs\AssociatePortal**.log]

disabled = 1

followtail = 0
sourcetype=iis
index=xxx_portals_iis_xxx

in props.conf

[iis]
pulldown_type = true
MAX_TIMESTAMP_LOOKAHEAD = 32
SHOULD_LINEMERGE = False
INDEXED_EXTRACTIONS = w3c
detect_trailing_nulls = auto
TRANSFORMS-SETNULL = setnullIISLOGS

in transform.conf

IIS Log Exclusions

[setnullIISLOGS]
REGEX = (\/__\w{6}.\w{4})
DEST_KEY = queue
FORMAT = nullQueue

in default props.conf
[iis]
pulldown_type = true
MAX_TIMESTAMP_LOOKAHEAD = 32
SHOULD_LINEMERGE = False
INDEXED_EXTRACTIONS = w3c
detect_trailing_nulls = auto
category = Web
description = W3C Extended log format produced by the Microsoft Internet Information Services (IIS) web server

Re: Why does Splunk "Show Source" not match IIS log file?

gcusello — Fri, 11 Oct 2019 07:00:50 GMT

Hi pzhou07920,
parsing is a job of Indexers (and eventually, if present, of Heavy Forwarders) so props.conf must be on Indexers.

Anyway, test you parsing (props.conf) using a text file on you pc, in this way you con check if iy's correct or not.

Bye.
Giuseppe

Re: Why does Splunk "Show Source" not match IIS log file?

pzhou07920 — Mon, 14 Oct 2019 19:40:17 GMT

Hi gcusello,

I added the log file that the error was occurring in into Splunk and the error did not occur. I did this via Add Data and extracted a portion of the IIS log file containing both concatenated records into a separate text file but the issue was not reproduced. I am currently at a loss for how to proceed.

Re: Why does Splunk "Show Source" not match IIS log file?

gcusello — Tue, 15 Oct 2019 07:10:11 GMT

Hi pzhou07920,
let me understand: why you say the the logs in show source (row 1) is composed by two logs concatenated?
each row should have a timestamp and I don't see any timestamp in the middle or in the second parts of you logs.

Then, did you tried to insert in your props.conf

TIME_FORMAT = %Y-%m-%d %H:%M:%S
TIME_PREFIX = ^

(the last row if the timestamp is at the beginning of the row, otherwise modify it).

Ciao.
Giuseppe

Re: Why does Splunk "Show Source" not match IIS log file?

pzhou07920 — Tue, 15 Oct 2019 12:37:39 GMT

Hi Gcusello,
They are concatenated where the first part of record1 is added with the second part of record 2. For example, record 1 is split into 2 parts, 1A and 1B. Record 2 is split into 2 parts, 2A and 2B. The record shown in Splunk is actually 1A + 2B.

In the logs I provided, The splunk source is made up of the first part of Record1 and the second part of record 2. Using the sections I bolded:
Record in Splunk Show Source = Part 1 matches First part of Splunk Source + Part 2 matches last part of Splunk Source

I editted the logs I provided to bold the separate parts and also bolded the location in the Splunk Show Source where the concatenation is occurring