[rfc][icedtea-web] fixing fatal impact of initialization of FileLog

[Jiri Vanek]

Hello here is extracted first art of the "tweeking filelogging" patch. Surprisingly the biggest one :)

J.

On 10/13/2015 06:15 PM, Jiri Vanek wrote:
> 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: fileLogInitializationError-1.6.patch
Type: text/x-patch
Size: 5581 bytes
Desc: not available
URL: <http://mail.openjdk.java.net/pipermail/distro-pkg-dev/attachments/20151014/fdc7b1a6/fileLogInitializationError-1.6.patch>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: fileLogInitializationError.patch
Type: text/x-patch
Size: 5609 bytes
Desc: not available
URL: <http://mail.openjdk.java.net/pipermail/distro-pkg-dev/attachments/20151014/fdc7b1a6/fileLogInitializationError.patch>