search

JDetmar / NLog.Extensions.AzureStorage

NLog Target for Azure Storage. Uses NLog batch write to optimize writes to Storage.
MIT License
31 stars 19 forks source link

Don't write to AzureDataTables #110

Closed m4ss1m0g closed 2 years ago

m4ss1m0g commented 2 years ago

Description

I have tried to write to AzureDataTables with a base example (see attached) without luck. I have tried several combinations, I have noticed that if the table does not exist it will create it and write once if I stop the program and re-run the message is not written. If the table already exists it never writes to it.

I have attached a small console app following the Nlog official .Net Core app

Environment

Windows 10 Pro netcoreapp3.1

Attachments

TestAzure.zip

snakefoot commented 2 years ago

Can you include the output from the NLog InternalLogger: https://github.com/NLog/NLog/wiki/Internal-Logging (internalLogLevel="Debug")

And attach the output from the 2 scenarios:

m4ss1m0g commented 2 years ago

Below are the files requested.

internal-nlog.table.exists.txt internal-nlog.table.notexisits.txt

snakefoot commented 2 years ago

Very strange. There are no errors.

internal-nlog.table.notexisits.txt says this: 2021-09-30 21:08:00.1656 Trace AzureTableStorageTarget(Name=azure): Requested Table Name: Foo 2021-09-30 21:08:00.5803 Debug AzureTableStorageTarget: Created table: Foo

internal-nlog.table.exists.txt says this: 2021-09-30 21:08:31.3233 Trace AzureTableStorageTarget(Name=azure): Requested Table Name: Foo

Curious if there is some flush/close-logic that needs to be improved. What happens if you run the application, and wait 30-60 secs before you Press ANY key to exit

snakefoot commented 2 years ago

You can also try to setup a AzureEventSourceListener that writes to console, and see if something is failing:

// Setup a listener to monitor logged events.
using AzureEventSourceListener listener = AzureEventSourceListener.CreateConsoleLogger();

See also: https://docs.microsoft.com/en-us/dotnet/api/overview/azure/data.tables-readme

snakefoot commented 2 years ago

Have also made a pull-request to improve the diagnostic logging in the AzureDataTables-NLog-target. See also: #111

You can download the pre-release nuget-package (and place it in a local-nuget-folder), and check if it gives some extra output:

https://ci.appveyor.com/api/buildjobs/yn8g4iq3rm8by8ln/artifacts/src%2FNLog.Extensions.AzureDataTables%2Fbin%2FRelease%2FNLog.Extensions.AzureDataTables.3.1.0.snupkg

m4ss1m0g commented 2 years ago

I've tried to:

  1. Wait 60 seconds (no effect)
  2. Added the AzureEventSourceListener it issue an error 409 Conflict, below the entire log 
    2021-10-01 09:48:53.4700||DEBUG|TestAzure.Runner|Doing hard work! Action1|
Press ANY key to exit
[Informational] Azure-Core: Request [9b3b5712-88b8-45ab-80cf-eda8901ef7e5] POST https://xxxx.table.core.windows.net/Tables?$format=REDACTED
x-ms-version:REDACTED
DataServiceVersion:3.0
Accept:application/json; odata=minimalmetadata
x-ms-client-request-id:9b3b5712-88b8-45ab-80cf-eda8901ef7e5
x-ms-return-client-request-id:true
User-Agent:azsdk-net-Data.Tables/12.1.0,(.NET Core 3.1.19; Microsoft Windows 10.0.19043)
x-ms-date:REDACTED
Authorization:REDACTED
Content-Type:application/json; odata=nometadata
client assembly: Azure.Data.Tables
[Warning] Azure-Core: Error response [9b3b5712-88b8-45ab-80cf-eda8901ef7e5] 409 Conflict (00.4s)
Cache-Control:no-cache
Transfer-Encoding:chunked
Server:Windows-Azure-Table/1.0,Microsoft-HTTPAPI/2.0
x-ms-request-id:e343fd6f-f002-0023-5e98-b6afa7000000
x-ms-client-request-id:9b3b5712-88b8-45ab-80cf-eda8901ef7e5
x-ms-version:REDACTED
X-Content-Type-Options:REDACTED
Date:Fri, 01 Oct 2021 07:48:55 GMT
Content-Type:application/json; odata=minimalmetadata; streaming=true; charset=utf-8
  3. I can't install the 3.1.0 version because the nuget raise an error, I have tried also with net5.0 
    dotnet add package nlog.extensions.azuredatatables -v 3.1.0                                                                                                       
Determining projects to restore...
Writing C:\Users\massimo\AppData\Local\Temp\tmp6CC6.tmp
info : Adding PackageReference for package 'nlog.extensions.azuredatatables' into project 'D:\Temp\AzureDataTables\TestAzure\TestAzure.csproj'.
info : Restoring packages for D:\Temp\AzureDataTables\TestAzure\TestAzure.csproj...
error: NU1202: Package NLog.Extensions.AzureDataTables 3.1.0 is not compatible withnetcoreapp3.1 (.NETCoreApp,Version=v3.1). Package NLog.Extensions.AzureDataTables 3.1.0 does not support any target frameworks.
error: Package 'nlog.extensions.azuredatatables' is incompatible with 'all' frameworks in project 'D:\Temp\AzureDataTables\TestAzure\TestAzure.csproj'.

    I have created a nuget.config pointing to local directory, and "pushed" your package.

<?xml version="1.0" encoding="utf-8"?>
<configuration>
    <packageSources>
        <add key="MyLocalSharedSource" value="d:\packages" />
    </packageSources>
</configuration>

Pushed with command nuget add D:\NLog.Extensions.AzureDataTables.3.1.0.snupkg -source d:\packages

Do you have somewhere the updated source code (I can't find any branches on your git repo), I can try to add to my project and debug.

Update

If I change the tableName (that not exist on Azure) on nlog.config and re-run below there are the AzureLog it raise 202 Accepted

2021-10-01 11:18:49.4758||DEBUG|TestAzure.Runner|Doing hard work! Action1|
Press ANY key to exit
[Informational] Azure-Core: Request [3f5b9cd9-1496-467f-8f15-b0ddbc244b98] POST https://xxxx.table.core.windows.net/Tables?$format=REDACTED
x-ms-version:REDACTED
DataServiceVersion:3.0
Accept:application/json; odata=minimalmetadata
x-ms-client-request-id:3f5b9cd9-1496-467f-8f15-b0ddbc244b98
x-ms-return-client-request-id:true
User-Agent:azsdk-net-Data.Tables/12.1.0,(.NET Core 3.1.19; Microsoft Windows 10.0.19043)
x-ms-date:REDACTED
Authorization:REDACTED
Content-Type:application/json; odata=nometadata
client assembly: Azure.Data.Tables
[Informational] Azure-Core: Response [3f5b9cd9-1496-467f-8f15-b0ddbc244b98] 201 Created (00.4s)
Cache-Control:no-cache
Transfer-Encoding:chunked
Location:REDACTED
Server:Windows-Azure-Table/1.0,Microsoft-HTTPAPI/2.0
x-ms-request-id:30bb81b9-5002-006a-01a5-b69cc7000000
x-ms-client-request-id:3f5b9cd9-1496-467f-8f15-b0ddbc244b98
x-ms-version:REDACTED
X-Content-Type-Options:REDACTED
Date:Fri, 01 Oct 2021 09:18:49 GMT
Content-Type:application/json; odata=minimalmetadata; streaming=true; charset=utf-8

[Informational] Azure-Core: Request [1b4f4534-eca4-4d01-832e-1c0e8c675b79] POST https://xxx.table.core.windows.net/$batch
x-ms-version:REDACTED
DataServiceVersion:3.0
x-ms-client-request-id:1b4f4534-eca4-4d01-832e-1c0e8c675b79
x-ms-return-client-request-id:true
User-Agent:azsdk-net-Data.Tables/12.1.0,(.NET Core 3.1.19; Microsoft Windows 10.0.19043)
x-ms-date:REDACTED
Authorization:REDACTED
Content-Type:multipart/mixed; boundary=batch_79059028-c4b9-4edf-811f-3a2c358774c1
client assembly: Azure.Data.Tables
[Informational] Azure-Core: Response [1b4f4534-eca4-4d01-832e-1c0e8c675b79] 202 Accepted (00.1s)
Cache-Control:no-cache
Transfer-Encoding:chunked
Server:Windows-Azure-Table/1.0,Microsoft-HTTPAPI/2.0
x-ms-request-id:30bb823a-5002-006a-7aa5-b69cc7000000
x-ms-client-request-id:1b4f4534-eca4-4d01-832e-1c0e8c675b79
x-ms-version:REDACTED
X-Content-Type-Options:REDACTED
Date:Fri, 01 Oct 2021 09:18:50 GMT
Content-Type:multipart/mixed; boundary=batchresponse_d5018bfe-dd0f-4f6a-a7a8-ae553efa5bf4

Another thing I noticed is that in this situation (can log) if I issue other log messages, this are logged correctly

Update 2

I found a possible error on row 422 of DataTablesTarget.cs:
var table = _client.GetTableClient(tableName);

When called it throws an Exception on the resulting object, 

_client.GetTableClient(tableName)
{Azure.Data.Tables.TableClient}
AccountName [string]:'_client.GetTableClient(tableName).AccountName' threw an exception of type 'System.ArgumentNullException'
Data [IDictionary]:{System.Collections.ListDictionaryInternal}
HResult [int]:-2147467261
HelpLink [string]:null
InnerException [Exception]:null
Message [string]:"Value cannot be null. (Parameter 'uri')"
ParamName [string]:"uri"
Source [string]:"Azure.Data.Tables"
StackTrace [string]:"   at Azure.Data.Tables.TableUriBuilder..ctor(Uri uri)\r\n   at Azure.Data.Tables.TableClient.get_AccountName()"
TargetSite [MethodBase]:{Void .ctor(System.Uri)}
Static members
Non-Public members
Name [string]:"Bar"
Static members
Non-Public members

on the next it throws the 409 error log await table.CreateIfNotExistsAsync(cancellationToken).ConfigureAwait(false);

This behavior can explain why it works when the table does not exist...

Update 3

I have made a PR https://github.com/JDetmar/NLog.Extensions.AzureStorage/pull/112 to fix this issue.

snakefoot commented 2 years ago

@m4ss1m0g Thank you for debugging this, and providing a fix. Would be nice that the Microsoft-Azure-Library actually failed with an exception, instead of just silently doing nothing.

snakefoot commented 2 years ago

Created https://github.com/Azure/azure-sdk-for-net/issues/24378 for Microsoft

snakefoot commented 2 years ago

@m4ss1m0g Guess the issue can be closed as resolved with https://www.nuget.org/packages/NLog.Extensions.AzureDataTables/3.1.0