Missing log messages and wrong order

[FloRup]

I use jsnlog with ASP and it's great. but now i have a problem. When generating a JSON file I had an error in a jQuery.each() iteration. To debug this I wrote some log messages to the console and also to a file. But in the file there were some messages in a wrong order and other messages are missing/lost...

I attached the console output which is always the same and also what is logged in the logfile. It always results in a different file (see last column)...

Any idea?!?

CONSOLE OUTPUT (which is right!):
jsnlog.min.js:19 generateJSON: TestListe
jsnlog.min.js:19 generateJSON: sign
jsnlog.min.js:19 generateJSON: eigene Checkbox (max2)
jsnlog.min.js:19 generateJSON: zweites Feld
jsnlog.min.js:19 generateJSON: erstes Feld
jsnlog.min.js:19 generateJSON: Produkt:
jsnlog.min.js:19 generateJSON: tgfgb
jsnlog.min.js:19 generateJSON: Artikel:
jsnlog.min.js:19 generateJSON: Bezeichnung:
jsnlog.min.js:19 generateJSON: Ausbau:
jsnlog.min.js:19 generateJSON: Anzahl:
jsnlog.min.js:19 generateJSON: Seriennummer:
jsnlog.min.js:19 generateJSON: Einbau:
jsnlog.min.js:19 generateJSON: Anzahl:
jsnlog.min.js:19 generateJSON: Seriennummer:
jsnlog.min.js:19 generateJSON: Beschreibung:
jsnlog.min.js:19 generateJSON: dritte Zeile
jsnlog.min.js:19 generateJSON: time
jsnlog.min.js:19 generateJSON: vierte zeile
jsnlog.min.js:19 generateJSON: Header
jsnlog.min.js:19 generateJSON: fünf
jsnlog.min.js:19 generateJSON: sechs
jsnlog.min.js:19 generateJSON: sieben
jsnlog.min.js:19 generateJSON: box
jsnlog.min.js:19 generateJSON:
jsnlog.min.js:19 generateJSON: list
jsnlog.min.js:19 generateJSON: pic
READY

FILE (First run)
2017-08-07 13:08:41.4369|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4360000Z|TestListe
2017-08-07 13:08:41.4369|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4390000Z|eigene Checkbox (max2)
2017-08-07 13:08:41.4369|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4380000Z|sign
2017-08-07 13:08:41.4625|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4420000Z|Produkt:
2017-08-07 13:08:41.4625|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4400000Z|zweites Feld
2017-08-07 13:08:41.4625|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4410000Z|erstes Feld
2017-08-07 13:08:41.4965|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4430000Z|tgfgb
2017-08-07 13:08:41.5226|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4450000Z|Bezeichnung:
2017-08-07 13:08:41.5226|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4460000Z|Ausbau:
2017-08-07 13:08:41.4965|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4440000Z|Artikel:
2017-08-07 13:08:41.8299|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4540000Z|Beschreibung:
2017-08-07 13:08:42.5553|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4470000Z|Anzahl:
2017-08-07 13:08:42.5708|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4510000Z|Anzahl:
2017-08-07 13:08:42.5708|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4490000Z|Einbau:
2017-08-07 13:08:42.6009|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4520000Z|Seriennummer:
2017-08-07 13:08:42.5708|INFO|jslogger||generateJSON|2017-08-07T11:08:41.4480000Z|Seriennummer:

FILE (Second run)
2017-08-07 13:10:49.0712|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0670000Z|TestListe
2017-08-07 13:10:49.0712|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0740000Z|Produkt:
2017-08-07 13:10:49.0712|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0720000Z|zweites Feld
2017-08-07 13:10:49.0712|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0730000Z|erstes Feld
2017-08-07 13:10:49.0712|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0690000Z|sign
2017-08-07 13:10:49.1249|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0760000Z|Artikel:
2017-08-07 13:10:49.1249|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0750000Z|tgfgb
2017-08-07 13:10:49.1389|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0760000Z|Bezeichnung:
2017-08-07 13:10:49.0712|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0710000Z|eigene Checkbox (max2)
2017-08-07 13:10:49.4834|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0820000Z|Seriennummer:
2017-08-07 13:10:50.1811|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0770000Z|Ausbau:
2017-08-07 13:10:50.1811|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0780000Z|Anzahl:
2017-08-07 13:10:50.2087|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0790000Z|Seriennummer:
2017-08-07 13:10:50.2087|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0800000Z|Einbau:
2017-08-07 13:10:50.2087|INFO|jslogger||generateJSON|2017-08-07T11:10:49.0810000Z|Anzahl:

my setup...

WEB.CONFIG:
<jsnlog serverSideMessageFormat="%logger|%url|%utcDate|%message" serverSideLogger="jslogger" productionLibraryPath="~/Scripts/jsnlog.min.js">

NLOG.CONFIG:

<target xsi:type="File"
          name="logger"
          fileName="${basedir}/app_data/logs/${shortdate}.log"
          createDirs="true"
          layout="${longdate}|${level:uppercase=true}|${logger}|${aspnet-request:serverVariable=HTTP_URL}|${aspnet-user-identity}|${message}"
/>

<target xsi:type="File"
              name="jslogger"
              fileName="${basedir}app_data/logs/${shortdate}.ljs"
              createDirs="true"
              layout="${longdate}|${level:uppercase=true}|${logger}|${aspnet-user-identity}|${message}"
/>
<rules>
    <logger name="jslogger" final="true" writeTo="jslogger" />
    <logger name="*" writeTo="logger" />
</rules>

ASPX/HTML:
<%= JSNLog.JavascriptLogging.Configure() %>

//JL logger output to console and file
var ajaxAppender = JL.createAjaxAppender('ajaxAppender');
var consoleAppender = JL.createConsoleAppender('consoleAppender');
JL().setOptions({ "appenders": [ajaxAppender, consoleAppender] });

I call it this way in js: JL("generateJSON").info($(this).attr("data-name"));

[mperdeck]

Looking at your logs and your web.config, I understand that the first column with times is generated on the server by NLog, while the second column was generated by JSNLog on the client.

If you were to sort your log by that second column (the one with the times generated on the client), you'll find that the order of events will always be the same.

The reason that ordering by the server generated dates doesn't work is that each log message travels over the network from client to server, and the order in which the messages arrive is not always the same as the order in which they were sent. This is not specific to JSNLog.

[TIPWARE]

... and why are some of the entries missing? the wrong order could be fixed. but I need all the entries!!!

[mperdeck]

I don't have enough information to find out why some entries are missing. If you put a small test app that reproduces the problem on GitHub, then I can reproduce it at my end.