Problem with logs.

[Wolfgang]

Hi,

I have 2 questions regardings logs (or 2 problems?).

During the end of the programm ~ 2500 results of computing are written back to DB. It took qquite a long time.

Using Telerik JustTrace it was shown that the largest amount of time was spend in :
26,75% OpenAccessRunTIme.DataObjects.LogDownLoader.runImp()
     26,75% System.Threading.Thread.Sleep(System.TimeSpan timeout)

(By the way - i like the code view of Ants a lot more. As we still have the full telerik suite (even only OpenAccess is normally used ) I gave it a try. With Ants I seem to see more details or seem to see problems faster , but that can also be that I'm missing a switch for another view or so. There you can see lines with execution timeor percentage per line)

Now I tried to peek into the DLL what possible could happen - tried JustDecompile - not so useful. But found the source button in JustTrace (funny it shows the code which i could not find in JustDecompile).

So first question: why should it be most of the time in LogDownLoader?
(maybe the question is better for JustTrace?)

I have the following section in <backendconfiguration>
 

<logDownloader.filename>C:\Users\Public\(withpathtouser)\DBLog</logDownloader.filename>
<logging.logEventsToTrace>true</logging.logEventsToTrace>
<logging.logEvents>errors</logging.logEvents>
<logDownloader.eventText>true</logDownloader.eventText>
<checkModelConsistencyOnCommit>False</checkModelConsistencyOnCommit>

Now I thought the log file would be large. It has taken time (even if it seems that it was mostly active sleeping?).

But the log itself was only a few kb.

13:05:48.782 pmf.start                   ***** Log Level: errors
13:23:04.088 sm.fetch                   *****.***** fe3542d3-4407-470b-ae68-87e2c5174e3e [default, -jdoreq] 0 state(s)
13:23:04.794 sm.fetch                   *****.*****fe35e4e7-d072-4f6d-9c77-b9efcf02a4c3 [default, -jdoreq] 0 state(s)

(i just put the names here to ***** , in log domain.classname was shown)

Given the question why it should take time to log 300 lines the next question is there: What should I do with this log? Honestly I cacnnot see what is going wrong. Where are the event texts? I only see sm.fetch, a class and a GUID. But what is going wrong? Where is something like an exeption text? What does such a line mean?

Cunfused regards
Wolfgang

[Ady]

Hello Wolfgang,

 When logging  is turned on (eventText - logs event to a text file) OpenAccess maintains an array of events. A background thread periodically writes these events to the file and then sleeps for the specified time interval (1 second by default). What you see is that this thread is waiting for the specified time interval.
When the singleton 'Database' instance is disposed (via call to Database.Dispose() or OpenAccessContext.DisposeDatabase()) OpenAccess writes all the pending events to the file and then disposes the Database instance. In your case this seems to be happening.
Have you intentionally turned on logging to the file?
What you see in the log are the events. For example -  'sm.fetch' denotes an event when an instance with a specific id is fetched. You can have a look at the Profiler for more information on how to make sense of the event information. Have you experienced an exception and no corresponding error text in the log?
In case you do not need that log you should turn off the logging.

All the best,
Ady
the Telerik team

[Wolfgang]

Hi Ady,

my main problem is the very large amount of time it takes to write the 2500 entries (9 textfields, 7 ints, 2 datetimes) to DB. With tracing with the telerik tracer it always shows the OpenAccessRunTIme.DataObjects.LogDownLoader.runImp() as main active thing.

I sometimes get an exception when i look for an object (if it's available in another DB). I would have expected, that in this case i would also get an entry in the log.

For example I try to look wether an object should be deleted in another db.

I query the ObjectScope - GetObjectByd and do not get an null object if it doesn't exist, but a Telerik.OpenAccess.Exceptions.NoSuchObjectException

(By the way, something like Exist(IObjectID) would have helped me alot in the situation, now i have an extry catch with NoSuchObjectException for something in program flow).

So why aren't this excpetions in the DB?

(I also hopped to see more in the log for the "hanging" GetObjectById where you answered to use ADO instead)

I will also take a look on the profiler.

Best regards,
Wolfgang 

[Ady]

Hello Wolfgang,

 The errors logged are all relational level errors and not logical errors. The query executed by GetObjectById does not find a row but also does not result in a relational level exception.
The newer API (OpenAccessContextBase) has a method 'TryGetObjectByKey' which does not throw and exception but there is nothing similar at the IObjectScope. You could also try a query like 'scope.Extent<Person>().Where(p => p.Id == id).FirstOrDefault()' - This will return a null although here you need to query against the id field and not an IObjectId instance.
Does switching off logging result in better performance for these 2500 inserts?

All the best,
Ady
the Telerik team