My.Application.Log.WriteEntry writes double entries!

Question

Has anyone had the experience in VB 2005 Beta 2 that when using the FileLog listener, each time My.Application.Log.WriteEntry is called to write a message, the message actually gets written to the <appname>.log file twice?

The log file is stored in directory "C:\Documents and Settings\<userid>\Application Data\<company name>\<appname>\1.0.0.0" with a file name of <xxx>.log and contains entries as follows:

DefaultSource Information 1001 20050718 15:25:53-SPSSearch Starting.
DefaultSource Information 1001 20050718 15:25:53-SPSSearch Starting.
DefaultSource Information 1003 20050718 15:25:58-SPSSearch Beginning search for (a) in (b).
DefaultSource Information 1003 20050718 15:25:58-SPSSearch Beginning search for (a) in (b).
DefaultSource Information 1004 20050718 15:26:00-SPSSearch Stopping search for (a) in (b).
DefaultSource Information 1004 20050718 15:26:00-SPSSearch Stopping search for (a) in (b).
DefaultSource Information 1002 20050718 15:26:01-SPSSearch Stopping.
DefaultSource Information 1002 20050718 15:26:01-SPSSearch Stopping.

Notice that every message appears twice!?
Yes, I am a newbie.

Answer 1

Matty, could you porivde more details regarding the repro? THat is, what does your code look like that produces this behavior? Are you writing the entries in an event for example (and perhaps the event is getting called twice)?

Regards,
Kit

Answer 2

Yes, thank you for your response.

The following code shows the sample where I am writing to the FileLog in two places from the ApplicationEvents.vb module:

Class MyApplication

Private Sub ApplicationStartup(ByVal sender As Object, ByVal e As Microsoft.VisualBasic.ApplicationServices.StartupEventArgs) Handles Me.Startup

My.Application.Log.WriteEntry(Format(Today, "yyyyMMdd") & " " & Format(TimeOfDay, "HH:mm:ss") & " SPSSearch Starting.", TraceEventType.Information, 1001)

End Sub

Private Sub ApplicationShutdown(ByVal sender As Object, ByVal e As System.EventArgs) Handles Me.Shutdown

My.Application.Log.WriteEntry(Format(Today, "yyyyMMdd") & " " & Format(TimeOfDay, "HH:mm:ss") & " SPSSearch Stopping.", TraceEventType.Information, 1002)

End Sub

End Class

The easy answer is that because these are in ApplicationStartup and ApplicationShutdow they MUST only run once, by definition.  However, I also set breakpoints and verified that these were each only visited once during the application lifetime.  By the way, I am simply starting and then closing the application.

The resultant log file contents for this sample are as follows:

DefaultSource Information 1001 20050719 08:50:07 SPSSearch Starting.
DefaultSource Information 1001 20050719 08:50:07 SPSSearch Starting.
DefaultSource Information 1002 20050719 08:50:16 SPSSearch Stopping.
DefaultSource Information 1002 20050719 08:50:16 SPSSearch Stopping.

I understand the contents of each line and where it comes from, but I do not see why each line is repeated.

In anticipation of your next question my app.config module looks as follows:

<?xml version="1.0" encoding="utf-8" ?>

<configuration>

<system.diagnostics>

<sources>

<!-- This section defines the logging configuration for My.Application.Log -->

<source name="DefaultSource" switchName="DefaultSwitch">

<listeners>

<!-- Uncomment the below section to write to the Application File Log -->

<add name="FileLog"/>

<!-- Uncomment the below section to write to the Application Event Log -->

<!--<add name="EventLog"/>-->

</listeners>

</source>

</sources>

<switches>

<add name="DefaultSwitch" value="Information" />

<!--This should work but does not (07-17-05)<add name="DefaultSwitch" value="All" />-->

</switches>

<sharedListeners>

<add name="FileLog"

type="Microsoft.VisualBasic.Logging.FileLogTraceListener, Microsoft.VisualBasic, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a, processorArchitecture=MSIL"

initializeData="FileLogWriter"/>

<!-- Uncomment the below section and replace APPLICATION_NAME with the name of your application to write to the Application Event Log -->

<!--<add name="EventLog" type="System.Diagnostics.EventLogTraceListener" initializeData="SPSSearch2"/>-->

</sharedListeners>

</system.diagnostics>

</configuration>

Again, thanks for your interest.
Matty

Answer 3

Ditto. Same problem here. I haven't seen an update to this thread in a month.

Answer 4

Unfortunately, this is a known bug in Beta2. It was fixed before release. It was caused by some changes in how the listeners get created that resulted in two FileLog listeners (our default and the one in the config file). Sorry for the inconvenience. As a work around, you can remove the extra listener from My.Application.Log.TraceSource.Listeners.

Craig Vick

VB Dev Team