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.