[RESOLVED] Log4net different name depending on call.

[sapator]

Hey.
I'm using it in a webapi but since this is not app specific I'm writing it here.
I am changing the name of the log file per web call. I'm wondering if there is a chance to overlap and write to the wrong file.
Again the call is per request.
Any idea?
The code is this:

 Public Shared Function ChangeLogFileName(ByVal appenderName As String, ByVal newFilename As String) As Boolean
    Dim rootRepository = log4net.LogManager.GetRepository()

    For Each appender In rootRepository.GetAppenders()

        If appender.Name.Equals(appenderName) AndAlso TypeOf appender Is log4net.Appender.FileAppender Then
            Dim fileAppender = TryCast(appender, log4net.Appender.FileAppender)
            fileAppender.File = newFilename
            fileAppender.ActivateOptions()
            Return True
        End If
    Next

    Return False
End Function

I'm not sure what will happen if 2 requests call ChangeLogFileName at the same time.

[Shaggy Hiker]

I'd say that's a valid concern. You appear to have a race condition, and it might not be simple to correct. My understanding is that different requests would be different processes. Changing the name would seem to mean that the If statement would create a race of a sort. It might not be a terrible problem, though.

Process A could see a file with the right name, then process B could see a file with the right name, then A would change the name, then B would change the name. The result would be the name supplied by B. That will only be an issue if A and B both go looking for the same file name. Whether or not it is an issue depends on whether or not you care what the final name is, and it doesn't seem like you would. After all, you don't seem to do anything with the name in the function, so whether it ends up as name A for a second then goes to name B, or it goes to name B for an hour then changes to name A, doesn't seem like it would matter from the code shown.

Changing the name itself doesn't look like it would be an issue. By the time you change the name, it might not be the name that it had when the If statement ran, but it will still get the new name. Does it matter if the name changes between the time you check it and the time you assign the new name?

[sapator]

Sorry I was caught up in the name to name to name changes and I'm confused.
What I currently doing is using a web api and when a get or post hits on controllerA, I change the name and write a value (do not change the name back) then when I get another call get post etc on controllerB I change the name and write a value (do not change the name back), so I'm not sure what will happen if call A changes the name and while continues to scroll down to write the value, service B reaches and change the name a micromillysecond before service A writes the value. Let my clarify that the log object is different per controller when declared, so I have
log4net.LogManager.GetLogger(typeof(controllerA))
and
log4net.LogManager.GetLogger(typeof(controllerB))
for the different controller calls. Does this make any difference? I don't have a clue.

[Shaggy Hiker]

I would be surprised if B changing the name affected A writing. Where you might run into issues is if B is writing when A is writing. The file isn't the name of the file. If A gets the file, then it no longer cares what the file name is. The name can be changed at will, because that's just an attribute of the file. A has the file, it no longer cares what that attribute is.

However, if A then writes to the file, it very much cares whether B is also writing to the file. Ideally, the file will be locked by A when it acquires it, but I have no idea whether or not that happens. If A locks the file, then B might flat out fail when it attempts to write. Alternatively, B could be forced to wait, which would be great. Failure by B is bad, waiting by B is good.

[sapator]

I'm not sure how a lock would happen.
Meaning I just tested by opening the file and then run the API to write to the file and it writes fine.
So I'm unsure of the mechanism the locks a file in VS.

[Shaggy Hiker]

I'm not thinking about VS, in that case. If you open an Excel spreadsheet, then somebody else can't also open the spreadsheet...except as read only. There must be some locking going on, which I have always assumed was at the Windows level. That may not be the case, though. I've never looked into it any.

If two processes can write to the same file at the same time, I would expect that would be quite bad. A file is a chunk of bytes stored somewhere. Presumably, when a process opens the file, it gets that chunk of bytes into process memory. If it then writes to that chunk of bytes, while another process also has that chunk of bytes in memory and is also writing to it, then you have a race condition, because they will write the chunk of bytes back to the HD in some order, and the last one will win.

[sapator]

Correct but the way I see it is like so (at worst)
A opens file
B changes the file name
A the writes to a "wrong file" *
B writes to the correct file for B but the wrong file for A

The key is at "*" , will A really write to the wrong file o Log4net has some mechanism to prevent that?
Does anyone knows that?
If it does not have a prevention mechanism what can be done?

[OptionBase1]

I'm not thinking about VS, in that case. If you open an Excel spreadsheet, then somebody else can't also open the spreadsheet...except as read only. There must be some locking going on, which I have always assumed was at the Windows level. That may not be the case, though. I've never looked into it any.

Not to derail the thread, but Excel had (and almost certainly still has in the most recent versions) the ability to "Share Workbook", where multiple people could be accessing and making changes to the spreadsheet at the same time. When you saved the spreadsheet, Excel would attempt to merge changes made by others in the interim with any potential changes you've made. It wasn't perfect, but it worked in the instances that I used it in previous jobs, with limited users and limited "simultaneous" changes.

[PlausiblyDamp]

Out off interest is there a reason you are changing the filename through code? What are the conditions that require a different filename?

It has been a while since I have used log4net but from what I remember the configuration allowed a lot of control over what messages got logged where.

[sapator]

Yes each controller code needs a different log.
These are some additional options:
https://stackoverflow.com/questions/...nder-file-path
The best I can see is using the %property but again isn't this like changing the file again? As in the example he is doing: log4net.GlobalContext.Properties["LogName"] = LogName;
Another example is this: value="%appdomain.log" it will het the executing assembly. If instead of this I could get the executing controller that would be an option , the name won't be the exact I want but still....
Also there is this problem with that solution: https://stackoverflow.com/questions/...-patternstring

Edit:
Another idea is creating another Appenders but all hell can break loose with this as it's on Live env and I have never tried to do something like that.

[PlausiblyDamp]

https://stackoverflow.com/questions/...tance-of-class might be useful, it effectively avoids the config files and dynamically builds the configuration up in code - that way you could create and name your appenders based on the classes.

[sapator]

Aha!
Just saw your post.
I was trying to get the appender from web.config , a second appender but it seems that a logger cannot get the appended from web config but only from a created object.
So this

  <log4net debug="true">	  
    <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
      <file value="Vlog\log.txt" />
      <appendToFile value="true" />
      <rollingStyle value="Size" />
      <maxSizeRollBackups value="10" />
      <maximumFileSize value="1000KB" />
      <staticLogFileName value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-5p %d %5rms %-22.22c{1} %-18.18M - %m%n" />
      </layout>
    </appender>
	  <appender name="RollingLogFileAppender1" type="log4net.Appender.RollingFileAppender">
		  <file value="Vlog\logx.txt" />
		  <appendToFile value="true" />
		  <rollingStyle value="Size" />
		  <maxSizeRollBackups value="10" />
		  <maximumFileSize value="1000KB" />
		  <staticLogFileName value="true" />
		  <layout type="log4net.Layout.PatternLayout">
			  <conversionPattern value="%-5p %d %5rms %-22.22c{1} %-18.18M - %m%n" />
		  </layout>
	  </appender>
	  <root>
      <level value="DEBUG" />
      <appender-ref ref="RollingLogFileAppender" />
    </root>
  </log4net>

although it will not complain it will also not work if you try logger.AddAppender

So yes I guess I can simulate an appended in code.
Thanks!

Edit. I also left alone the first controller so one get the values from web.config and the other programmatically.

[sapator]

Unfortunately I'm returning to this.
Complete crap when using a web.config RollingLogFileAppender and add on code a RollingLogFileAppender .
It writes to both files specified on the RollingLogFileAppender's .

What I might do next week is removing the web.config RollingLogFileAppender file specs and only use code to change them but even if it works, this needs test again before going live and I think I can live with a wrong log write once a month rather than monkeying around.