[keycloak-dev] testsuite still eats server-side logs in IDE

Wed Apr 5 03:48:21 EDT 2017

Actually it's probably the combination of WildFly log output and the test
log output that generates 4mb+.

Maybe we could write a custom appender that buffers everything between
"<test> STARTED" and FAILED/FINISHED. If it's a FINISHED it will just clear
the buffer, but if it's a FAILED it will output to std out. We could also
add a log output per test class. We could make it an option when running
the tests (something like -PshowFailuresOnly). So output on Travis/Jenkins
would be something like:

[UndertowDemoFilterServletAdapterTest] Starting

[UndertowDemoFilterServletAdapterTest] historyOfAccessResourceTest() STARTED

... Loads of stuff ...

[UndertowDemoFilterServletAdapterTest] historyOfAccessResourceTest() FAILED

[NextTest] Starting

[NextNextTest] Starting

Results :

Tests run: 335, Failures: 1, Errors: 0, Skipped: 12

On 5 April 2017 at 09:25, Marek Posolda <mposolda at redhat.com> wrote:

> Btv. I've just saw some logs of the wildfly job. And there are some
> differences between undertow and Wildfly.
>
> With undertow, the maven job has disabled logging for "org.keycloak", so
> the expected exceptions are not displayed in the log. However with Wildfly
> job, they are still displayed. This is likely the reason why the 4MB limit
> on travis was reached with Wildfly.
>
> I think the reason is, that Wildfly logging needs to be configured in
> standalone/configuration/standalone.xml in logging subsystem, hence
> disabled "org.keycloak" in testsuite/integration-
> arquillian/tests/base/src/test/resources/log4j.properties has no effect.
>
> So it seems that for Wildfly we need to ensure that logging subsystem in
> standalone.xml is properly configured and add the appender here as well if
> we do the appender (which maybe means adding another module or library with
> the appender etc). And we need to do that in the preparation of all the
> various wildfly servers (wildfly, adapter, cluster etc).
>
> Marek
>
>
>
> On 05/04/17 08:34, Stian Thorgersen wrote:
>
> Ok, so not for the IDE then. It's not really needed for the IDE anyways as
> at least IntelliJ is smart enough to group output per test so it's easy to
> find relevant info.
>
> On 4 April 2017 at 16:23, Marek Posolda <mposolda at redhat.com> wrote:
>
>> IMO it works for travis/jenkins, but doesn't work for IDE.
>>
>> When debugging in IDE, you usually want to see all the test output even
>> if test not failing. You want to see it immediately. And the thread you're
>> debugging is in many cases different then the thread, which is expected to
>> output something to console log (eg. when debugging the test method, you
>> want to check that after calling the line with
>> "oauthClient.openLoginForm()" the server called the expected HTTP requests
>> and wrote the expected items to the log etc).
>>
>> Also some of us use the pattern like this when developing something:
>>
>> @Test
>> public void testSleep() {
>>  Thread.sleep(10000000);
>> }
>>
>> in which case you usually just test the Keycloak server/UI directly and
>> test is here just to prepare the environment, which is done in @Before
>> methods etc. This test method is never finished and hence never failed. But
>> still, you want to see the log/console output immediately when you're
>> testing stuff.
>>
>> Marek
>>
>>
>>
>> On 04/04/17 15:53, Stian Thorgersen wrote:
>>
>> Wouldn't simply only showing log output from failed tests solve all
>> issues? In the IDE you get the debug info you need to resolve a failing
>> test. On Travis or Jenkins you get the details you need to look into failed
>> tests without having X megabytes of test output, expected exceptions, etc..
>>
>>
>> On 4 April 2017 at 15:11, Marek Posolda <mposolda at redhat.com> wrote:
>>
>>> Hmm... I guess it might be "org.xnio" ? As we have "org.xnio" and
>>> "org.hibernate" switched to OFF. Some other categories (resteasy etc) are
>>> switched to WARN.
>>>
>>> Maybe we can have different log4j files used when running from IDE and
>>> from maven? As when running from IDE, you are usually debugging/tracing one
>>> particular test and you want all the logging enabled in the console for
>>> most of the libraries. When with maven it is the opposite and we want to
>>> reduce console logging as much as possible.
>>>
>>> Marek
>>>
>>>
>>> On 04/04/17 15:00, Bill Burke wrote:
>>>
>>> The error that was eaten was something thrown from Undertow before it
>>> even got to org.keycloak code.
>>>
>>> On 4/4/17 8:00 AM, Stian Thorgersen wrote:
>>>
>>> This will help with those cases where you currently see a whole bunch of
>>> exceptions in the logs where they are actually expected
>>>
>>> On 4 April 2017 at 13:44, Marek Posolda <mposolda at redhat.com> wrote:
>>>
>>>> +1
>>>>
>>>> It will be good if it logs the details for whole class in case that
>>>> some test failed. As there could be dependencies between the order in which
>>>> test method was executed etc.
>>>>
>>>> Also we can have an appender, which will log everything to the file. So
>>>> if you still want to see full log and all the details, you can look to the
>>>> file.
>>>>
>>>> Marek
>>>>
>>>>
>>>>
>>>> On 04/04/17 12:26, Stian Thorgersen wrote:
>>>>
>>>> Here's a cray thought. Could we somehow hide all log output for a test
>>>> that passes and only show log output for failed tests? Maybe it could be
>>>> done with a custom log appender that buffers log output, then the unit
>>>> tests could call clear or dump depening on success/failure.
>>>>
>>>> On 4 April 2017 at 12:24, Stian Thorgersen <sthorger at redhat.com> wrote:
>>>>
>>>>> I think this probably still needs some work. When running from IDE we
>>>>> don't need the TestEventsLogger at all as the IDE (at least IntelliJ) deals
>>>>> with that in a much nicer way.
>>>>>
>>>>> When running on Travis there's probably still an issue with to much
>>>>> log being generated. I can try this again, but last time I tried with
>>>>> -Pauth-server-wildfly the sysoutput file became to big (4mb+).
>>>>>
>>>>> On 4 April 2017 at 10:21, Marek Posolda <mposolda at redhat.com> wrote:
>>>>>
>>>>>> I found some workaround to fix that. PR sent here:
>>>>>> https://github.com/keycloak/keycloak/pull/4002
>>>>>>
>>>>>> Now the default logging level for "org.keycloak" is INFO when you run
>>>>>> from IDE, but disabled when you run with maven-surefire-plugin. In both
>>>>>> cases, system property "keycloak.logging.level" can be used to override the
>>>>>> default.
>>>>>>
>>>>>> Marek
>>>>>>
>>>>>>
>>>>>> On 04/04/17 09:24, Stian Thorgersen wrote:
>>>>>>
>>>>>> Pavel - can you comment on this please? If I remember correctly it
>>>>>> wasn't working initially, then Marek fixed it, but now it's broken again.
>>>>>>
>>>>>> On 3 April 2017 at 22:06, Marek Posolda <mposolda at redhat.com> wrote:
>>>>>>
>>>>>>> Doesn't work here too. But it worked a month ago or so. Not sure
>>>>>>> what changed in the meantime... Created
>>>>>>> https://issues.jboss.org/browse/KEYCLOAK-4705 . Will try to take a
>>>>>>> look.
>>>>>>>
>>>>>>> Marek
>>>>>>>
>>>>>>> On 03/04/17 16:22, Bill Burke wrote:
>>>>>>>
>>>>>>>> And that helps how?  Running in IDE should not suppress any error
>>>>>>>> messages.  The error message was actually an internal Undertow one
>>>>>>>> complaining that async HTTP was unsupported.  I did look in the
>>>>>>>> log4j
>>>>>>>> properties.  The default logging level looks like it is INFO.
>>>>>>>>
>>>>>>>>
>>>>>>>> On 4/3/17 9:33 AM, Stian Thorgersen wrote:
>>>>>>>>
>>>>>>>>> https://github.com/keycloak/keycloak/blob/master/testsuite/i
>>>>>>>>> ntegration-arquillian/HOW-TO-RUN.md#testsuite-logging
>>>>>>>>>
>>>>>>>>> On 1 April 2017 at 21:22, Bill Burke <bburke at redhat.com
>>>>>>>>> <mailto:bburke at redhat.com>> wrote:
>>>>>>>>>
>>>>>>>>>      When running arquillian tests in the IDE, I'm still seeing no
>>>>>>>>> log
>>>>>>>>>      messages from the server.  I had to set a breakpoint in
>>>>>>>>> JAX-RS code to
>>>>>>>>>      find out a Javascript parsing error.
>>>>>>>>>
>>>>>>>>>      _______________________________________________
>>>>>>>>>      keycloak-dev mailing list
>>>>>>>>>      keycloak-dev at lists.jboss.org <mailto:keycloak-dev at lists.jbo
>>>>>>>>> ss.org>
>>>>>>>>>      https://lists.jboss.org/mailman/listinfo/keycloak-dev
>>>>>>>>>      <https://lists.jboss.org/mailman/listinfo/keycloak-dev>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> _______________________________________________
>>>>>>>> keycloak-dev mailing list
>>>>>>>> keycloak-dev at lists.jboss.org
>>>>>>>> https://lists.jboss.org/mailman/listinfo/keycloak-dev
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>
>>>>
>>>
>>>
>>>
>>
>>
>
>