[rfc][icedtea-web] pre-review - accidental logging tweeking

[Jiri Vanek]

Hello!

This (small!!) patch is doing several things. I will post them separately but as about 4x4 ways is 
leading to destination, I wont to share thoughts before fulfilling targets of this multi-patch

It started by one bug report and one future request.
  1 - the bug is, that if set logging to files, and put blocked destination as ustom log file (eg 
"/")  whole logging crashes, as initializer of FileLog keeps crashing with classNotFound.
  2 - the feature request was add file-logging of applications run inside in itw. I agreed on that 
that as it gave quite an sense and was supposed to be easy. INstead it reviled one fragile area in 
logging.

Two issues I found during implementation of those two above
  3 - when verbose is on - junittest may deadlock
     - it went even more wrong during original impelmentations of implementation of 1
  4 - for some already forgotten reason we are using java.util.logging as main logging facility for 
filelogging.
     - imho it is overcomplicated - several synchronizations on unexpeted palces and overall 
complication, where bufferedwritter.write(string) may be enough.
    - as side effect, we may get deadlock anytime application is using custom implementation of 
logger - I faced several on Elluminate. And again it went worse (here read: deadlock was more probable)

So - the first is bug, and should be fixed for both head and 1.6 I fixed it by moving 
initializxations to factory method and returning dummy SimpleLogger  doing nothing if exception 
occures. Its this part:


+ public static SingleStreamLogger createFileLog(FileLogType t) {
+        SingleStreamLogger s;
+        try {
+            s = new FileLog(t);
+        } catch (Exception ex) {
+            //we do not wont to block whole logging just because initialization error
+            OutputController.getLogger().log(ex);
+            s = new SingleStreamLogger() {
+
+                @Override
+                public void log(String s) {
+                    //dummy
+                }
+
+                @Override
+                public void close() {
+                    //dummy
+                }
+            };
+        }
+        return s;
+    }

Part of it was refactoring in OutputController where FileLogHolder have to keep interface of 
SingleStreamLogger ratehr then impelmentation of FileLog and implying override of close().



When I promissed (2), I thought  that I will just create
+    private static class getAppFileLog {
+
+        //https://en.wikipedia.org/wiki/Double-checked_locking#Usage_in_Java
+        //https://en.wikipedia.org/wiki/Initialization_on_demand_holder_idiom
+        private static volatile SingleStreamLogger INSTANCE = 
FileLog.createFileLog(FileLog.FileLogType.CLIENTAPP);
+    }
+
+    public SingleStreamLogger getAppFileLog() {
+        return getAppFileLog.INSTANCE;
+    }

next to already existing getFileLog and FileLogHolder.

and on place of
	 //clients app's messages are reprinted only to console
	         if (s.getHeader().isClientApp){
	             return;
	         }
I will jsut log one more line.

However, I found that any modifications here leads to immidate unexpeted and rpetty serious deadlock 
- during various unittest,inruntime and so on... I solved them by adding second
queue and second consume. Well I' was not happy from that... But if (4) will not be faced, it will 
remain the only option for this approach.

When I screwed implementation of (2) so much, that the deadlock in Elluinate was 100% I tried to 
debug it, but as I ended in case that it is theirs custom Logger implementation which is the root 
cause. So I tried to rework FileLog so it do not rely in java.util.logging,but on simple FileWriter.
Astonishingly it solved both (3) and (4) - when only (4) was target.


For (2) there is one more approach, of which I'm not 100% sure what impact it may have.  That 
approach is to get rid of teeOutptuStream's logic.
Just for reminder - itw is taking stdout/err and is repalcing them by TeeoutputStreem which a) send 
what it get to original stream and (as second end of Tee) it logs this utput to our console.
My idea is, to get rid of this duplcate-streams logic, and only log the stuff our client aplication 
is printing,  And when que of logged messages is read, print it to stdout/err as originall 
application originally desired. Benefit will be, that this logging exeption will be rid of, but 
drawback will be possile lagging of messages.
If this approach will be taken, then I think the seond queue+conslumer will not be needed for (2)


Now - I would like to fix (1) - i think the patch is ok, I will send it separately, and (1) will be 
fixed for head and 1.6. Mybe push it as it is after some silence on this patch.

Then, I would like to implement (2) and fix (4) ideally also (3)
To do so, I need - a)get rid  of teeOutputStream or/and b)getRid of our misuse of java.util.Logging 
and/or/maybeNot implement the second queue (its based on what of  a) and/or b) will be seelcted.

As I do not know any other cure for (3) then (b), I'm  voting for following my patch in this email, 
and to repalce java.util.logging by FileWriter - we do not need whole Logging chain in ITW - afaic ...


I) If (b) will be agreed on first , then implementation of (2) should be revisited and I will again 
check what is more suitable - whether change of TeeStreem or new Queue+consumer (maybe none? but 
that I doubt a bit)

II) if removal of TeeStream in favour of logging and reprinting custom client apps outputs willbe 
agreed then (b) should be revisited if needed for (2) - but as it is the only cure for (3) and issue 
with (4) is just more hodden, thenI'm really for (I)


Thoughts?

  J.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: tweekingOfLogging.patch
Type: text/x-patch
Size: 14393 bytes
Desc: not available
URL: <http://mail.openjdk.java.net/pipermail/distro-pkg-dev/attachments/20151013/4fd50e8c/tweekingOfLogging-0001.patch>