urielha / log4stash

Module to Log log4net Messages to ElasticSearch
MIT License
60 stars 44 forks source link

System.NullReferenceException: Object reference not set to an instance of an object #55

Closed Koshak118 closed 4 years ago

Koshak118 commented 5 years ago

Hi

Thanks for creating this awesome framework

The integration with the local Docker EK stack went smooth, but when I trying to connect to the AWS Kibana it get crashed with the aforementioned error and the stack trace is as the following:


System.NullReferenceException: Object reference not set to an instance of an object.
   at log4stash.WebElasticClient.CheckResponse(IRestResponse response) in d:\uriel\Programing\C#\log4stash\src\log4stash\ElasticClient\WebElasticClient.cs:line 203
   at log4stash.WebElasticClient.SafeSendRequestAsync(RequestDetails request) in d:\uriel\Programing\C#\log4stash\src\log4stash\ElasticClient\WebElasticClient.cs:line 165

My conf is

<log4net>
  <appender name="ElasticSearchAppender" type="log4stash.ElasticSearchAppender, log4stash">
    <Server>******es.amazonaws.com</Server>
    <Port>9200</Port>
    <Ssl>true</Ssl>
    <IndexName>log_test_%{+yyyy-MM-dd}</IndexName>
    <IndexType>LogEvent</IndexType>

    <AuthenticationMethod>
      <!--For AWS ElasticSearch service-->
      <Aws>
        <Aws4SignerSecretKey>***</Aws4SignerSecretKey>
        <Aws4SignerAccessKey>***</Aws4SignerAccessKey>
        <Aws4SignerRegion>***</Aws4SignerRegion>
      </Aws>
    </AuthenticationMethod>

    <ElasticFilters>
      <!-- example of using filter with default parameters -->
      <Json>
        <SourceKey>JsonRaw</SourceKey>
        <FlattenJson>false</FlattenJson>
        <!-- the separator property is only relevant when setting the FlattenJson property to 'true' -->
        <Separator>_</Separator>
      </Json>
    </ElasticFilters>
  </appender>
  <root>
    <level value="ALL" />
    <appender-ref ref="ElasticSearchAppender" />
  </root>
</log4net>

Any ideas?

urielha commented 5 years ago

Hi @Koshak118 ! That's odd because it seems like the line of the exception is var stringResponse = response.Content; But there is a null validation the line before so that's doesn't make sense.

Just to verify - what version are you using?

Koshak118 commented 5 years ago

Hi @urielha

Yep, that's weird, because there is a validation that the response is not null just before the line where it get crashed. The version I am using is the "latest stable 2.2.1". Is there any chance it does not have the latest source?

Koshak118 commented 5 years ago

Anyway it would be helpful to print the return code of the response to get an intuition what went wrong. I guess it is an authorization issue, but have no way to verify it. Playing around with the AWS ES service access policy did not helped, so I have no idea what else might be wrong.

Koshak118 commented 5 years ago

Hi @urielha

Happy New Year, first of all!

Any update on this issue?

urielha commented 5 years ago

Happy new year! I didn't have time to check this but planning to.

You ask earlier if there is a chance that the code is different, I tag every release so you just have to browse the correct tag: https://github.com/urielha/log4stash/tree/log4stash-2.2.1

I verified again and the line is the same: https://github.com/urielha/log4stash/blob/log4stash-2.2.1/src/log4stash/ElasticClient/WebElasticClient.cs#L203

Koshak118 commented 5 years ago

Hi @urielha

I get your point, so I've double checked the installed version, and it is 2.2.1 and the crash is still happening when working with this version. See screenshots attached

log4stash nuget

log4stash error

Looks weird indeed

eran-gil commented 5 years ago

I see 2 options:

  1. This is some kind of dotnet voodoo that results from an unexpected response.
  2. A bug in RestSharp. I decompiled the RestSharp code for the getter method of 'Content' and it has some potential for an error: public string Content { get { return this.content ?? (this.content = this.RawBytes.AsString()); } set { this.content = value; } }

I suggest using a web-debugger (like 'Fiddler' when using windows) and trying to analyze the response from your ElasticSearch cluster. It might be a bug in the AWS authentication code in the library, so the only way to verify it is using such a debugger.

Please let us know of the results or open a pull request so we can fix this bug.

Koshak118 commented 5 years ago

Hi @erangil2

I am using .NET.Core v 2.1 for my client application. Fiddler does not see connections coming from it and looks like this is known issue.

I think about compiling the source code and trying to debug in on my local machine by adding some more logs. The whole project looks pretty much complicate though, could you guide me through the process of creating a resulting DDL I can throw in my Nuget rep to replace the official one?

urielha commented 5 years ago

Hi, I hope the details below will guide you:

Compiling

You should compile the project using this csproj: src/log4stash/log4stash.csproj.
I think running dotnet build from the same folder should do.

In my opinion, don't replace the nuget package - just uninstall it and add a direct reference to your local compiled dll.

Or, You can also test it from log4stash solution:

Debugging

The main class (the actual appender) is src/log4stash/ElasticSearchAppender.cs. Although, you only need to focus on this file: src/log4stash/ElasticClient/WebElasticClient.cs and more specific, on SafeSendRequest/Async functions that handle the actual requests

Koshak118 commented 5 years ago

Hi @urielha

Thanks for the guidance, I am able now to compile the log4stash project locally

A quick question after the compilation - the target framework of the log4stash project is .NET.4.5 and I am using it for .Net.Core 2.1 app. Not a healthy situation, which might (or might not) explain the voodoo. The README does specify it is compatible with .NET.Core but I do not see how it is implemented.

Do I miss something?

Koshak118 commented 5 years ago

Anyway, tried to run log4stash.Test project with my configuration and got into the following issue:

For some reason ElasticSearchAppender.Servers is populated twice with the same configuration; this leads for the crash when trying to create WebElasticClient() at https://github.com/urielha/log4stash/blob/log4stash-2.2.1/src/log4stash/ElasticClient/WebElasticClient.cs#L56 - it throws a "System.ArgumentException: 'An item with the same key has already been added.'" exception which totally makes sense, since the server URL is the same

Tried to debug this code but with no success - too many loops/iterators/Dictionary constructors are being called under the hood making it difficult to investigate. Obviously the argument for IndexOperationParamsDictionary.ToDictionary() function cannot be created on the fly without a prior sanitation of the ServerDataCollection object.

Didn't proceed further than that, guess this issue might be the core one for all the mess.

Let me know if the above helps

urielha commented 5 years ago

Thanks @Koshak118 that's helped a lot! First of all you are right, we need to make a dedicated build for dotnet core which is in the backlog.

Secondly, the exception you've found might help us solve the issue, let me do some checking and I will update soon

urielha commented 5 years ago

It's weird, it seems like your "System.ArgumentException" is not related, are you sure you have only one <Sever> tag? Anyway we should look into it because it is not acceptable.

On other hand, I also got NullReferenceException but at a later line (I already have prepared fix for this but didn't had time to publish). I will publish today a pre-release and let's see if this solve your issue 🤷‍♂️

urielha commented 5 years ago

OUCH, how didn't I notice?! You have included the "https//" as the server name.

I know this is not so intuitive, I might add auto correct if the "https" is included.

Please update me if problem solved.

I will have to clean / fix some things anyway but I hope you won't be blocked anymore.

Thanks!

Koshak118 commented 5 years ago

Hi @urielha

Glad I could help

Nope, the hostname without "https://" didn't make any difference. I've caught the System.ArgumentException to see whether I can proceed and get to the original issue but it gets crashed now trying to get a rest client:

Exception thrown: 'System.NullReferenceException' in log4stash.dll
log4net:ERROR Invalid request to ElasticSearch
System.NullReferenceException: Object reference not set to an instance of an object.
   at log4stash.WebElasticClient.get_RestClient()
   at log4stash.WebElasticClient.<SafeSendRequestAsync>d__14.MoveNext()

All that running the test project. The hostname without "https://" in my app didn't help either.

P.S. I've updated the very first post of the thread with the actual configuration so you can easily reproduce the issue. I think it does not have double "" tag, am I right?

urielha commented 5 years ago

@Koshak118 , I used your configuration (I edited it after I took the connection details) and after I removed the https:// and added the <Ssl> tag the logging has been succeeded.

I will try again with the new configuration you updated but I believe it will work.

Koshak118 commented 5 years ago

@urielha

And you do not have that System.ArgumentException? Weird, cause that's the flow - that code is called once upon appender constructor and another time when adding configuration.

Can we have a short Skype debug session so I can share a screen?

urielha commented 5 years ago

Hi, No, I don't have that exception, I think it has something to do with dotnet core but I'm really not sure. I'm working on adding full support on it but I don't have much time to publish full version right now.

Meanwhile please try this pre release: https://www.nuget.org/packages/log4stash/2.2.2-pre on your original project. I fixed some error message so now you should see what was the actual problem.

Crossing fingers

urielha commented 5 years ago

By the way, now using your configuration I'm getting a timeout from the server, maybe the service went down?

About the Skype - let's hope the pre release version will do the magic because I'm not sure I can be available.

Koshak118 commented 5 years ago

Hi @urielha

I'll give the pre-release version a try shortly and will update.

Regarding the server timeout - there is an access policy which restricts it to the specific user, so a request from any other one ends up with a timeout.

Koshak118 commented 5 years ago

Well, it is a timeout for me as well, so, as I thought, it's the access policy configuration issue.

Thanks for adding more comprehensive output, now it much more clear :

log4net:ERROR Got error while reading response from ElasticSearch
System.InvalidOperationException: Some error occurred while sending request to Elasticsearch.
System.Net.WebException: The operation has timed out.
   at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
   at RestSharp.Http.GetRawResponseAsync(IAsyncResult result, Action`1 callback)
   at RestSharp.Http.ResponseCallback(IAsyncResult result, Action`1 callback)
   at log4stash.WebElasticClient.CheckResponse(IRestResponse response) in d:\uriel\Programing\C#\log4stash\src\log4stash\ElasticClient\WebElasticClient.cs:line 243
   at log4stash.WebElasticClient.SafeSendRequestAsync(RequestDetails request) in d:\uriel\Programing\C#\log4stash\src\log4stash\ElasticClient\WebElasticClient.cs:line 165
Koshak118 commented 5 years ago

The latest update for the issue:

It turns out that the ELK stack AWS automatically deploys does not open/use a default 9200 port, so trying to access it ends up with the time out error. The port to use in this case is 443.

The tricky thing here that in some configurations (such as VPC) the timeout error may indicate access policy error, so it took me a while to eliminate this hypotheses

@urielha , I think it worth README update and might save a lot of time for other ppl.

urielha commented 5 years ago

Thanks a lot @Koshak118 ! I glad to hear you've found the problem.

I have number of take backs from this thread and planning to correct some things accordingly.

I will leave this issue open until an official realse will be out.