Add SLF4J logging support for Appium local service #1014

alexander-poulikakos · 2018-08-31T07:57:52Z

Change list

Add possibilty to enable server output data logging through SLF4J loggers. This allow server output data to be configured with your preferred logging frameworks (e.g. java.util.logging, logback, log4j).

Types of changes

No changes in production code.
Bugfix (non-breaking change which fixes an issue)
New feature (non-breaking change which adds functionality)
Breaking change (fix or feature that would cause existing functionality to not work as expected)

Details

Normal use case:

	    AppiumDriverLocalService service = ...
	    service.clearOutPutStreams();
	    service.enableDefaultSlf4jLoggingOfOutputData(); // <-- add this method call
	    service.start();

By default log messages are:

logged at INFO level, unless log message is pre-fixed by [debug] then logged at DEBUG level.
logged by a SLF4J logger instance with a logger name corresponding to the appium sub module as prefixed in log message (logger name is transformed to lower case, no spaces and prefixed with "appium.service.").

Example of log messages:

Log message "[ADB] Cannot read version codes of " is logged by logger: appium.service.adb at level INFO
Log message "[debug] [XCUITest] Xcode version set to 'x.y.z' " is logged by logger appium.service.xcuitest at level DEBUG

More general purposes
These methods are provided for more general use cases:

service.addSlf4jLogMessageConsumer(BiConsumer);
service.addLogMessageConsumer(Consumer)

mykola-mokhnach · 2018-08-31T08:03:03Z

Please adjust indentation in all source files

mykola-mokhnach · 2018-08-31T08:05:49Z

src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java

+     */
+    public void enableDefaultSlf4jLoggingOfOutputData() {
+        addSlf4jLogMessageConsumer((logMessage, ctx) -> {
+            if (ctx.level().equals(DEBUG)) {


This mapping is not sufficient, since Appium server uses more levels, for example warn and error

Will add the other levels as well.

Hmm, I have never seen an actual log message on either warn/error level. Do you know if they follow same format as debug? i.e. log message is prefixed with log level. Info level tag is not added in log message.

I was just able to trigger a WARNmessage, but there is no log level indication in the log message it self. So will ignore warn and error levels for now.

Example

[Appium] Deprecated server args: [Appium] --device-name => --default-capabilities '{"deviceName":"someName"}'

According to this, the above log message is at WARNlevel:
https://github.com/appium/appium/blob/7a00b3f875991ba1d95359ed53a3eda47911f64b/lib/main.js#L44

the actual level is added there if logging timestamp is enabled:

2018-08-31 08:17:13:813 - info: [debug] [JSONWP Proxy] Got response with status 200: {"value":{"using":"class chain","value":"**/XCUIElementTypeCollectionView[`name == 'add_participants.list'`]/XCUIElementTypeCell[$name == 'user_cell.name' AND value == 'qrj7pcz5'$]","description":"unable to find an element"},"sessionId":"A4FBAD14-ED57-46D4-9407-B91C76BCB415","status":7} 2018-08-31 08:17:13:814 - info: [debug] [MJSONWP] Matched JSONWP error code 7 to NoSuchElementError 2018-08-31 08:17:13:815 - error: [W3C] Encountered internal error running command: NoSuchElementError: An element could not be located on the page using the given search parameters. 2018-08-31 08:17:13:815 - error: [W3C] at XCUITestDriver.callee$0$0$ (/usr/local/lib/node_modules/appium/node_modules/appium-xcuitest-driver/lib/commands/find.js:130:13)

mykola-mokhnach · 2018-08-31T08:06:31Z

src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java

+
+    static Slf4jLogMessageContext parseSlf4jContextFromLogMessage(String logMessage) {
+        Matcher m = LOGGER_CONTEXT_PATTERN.matcher(logMessage);
+        String loggerName = "appium.service";


This should be in the constant

I'm not following you on this. What should be in the constant? Which constant?

private static final String LOGGER_NAME

mykola-mokhnach · 2018-08-31T08:08:03Z

src/main/java/io/appium/java_client/service/local/Slf4jLogMessageContext.java

+	 * @return {@link Logger} instance associated with this context.
+	 * 
+	 */
+	public Logger logger() {


java getters usually start with get

will fix that

alexander-poulikakos · 2018-08-31T08:11:16Z

thanks for comments! What should I adjust indentation to? it seems to match the rest of the code lines.

alexander-poulikakos · 2018-08-31T09:18:32Z

@mykola-mokhnach Can you please give more context regarding you comment Please adjust indentation in all source files. What should the indentation? I don't see it differ from other code lines.

mykola-mokhnach · 2018-08-31T09:23:23Z

alexander-poulikakos · 2018-08-31T09:29:50Z

@mykola-mokhnach How many spaces should it be per indentation?

mykola-mokhnach · 2018-08-31T09:30:28Z

4 spaces

alexander-poulikakos · 2018-08-31T12:39:25Z

@mykola-mokhnach
getter names fixed
indentation fixed
constant fixed
javadoc fixed

regarding loglevel error and warn I'm skipping those according to comment above (log level tag is not present in log message -> can't parse it)

Anything else that I have missed?

mykola-mokhnach · 2018-08-31T12:41:03Z

src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java

+     */
+    public void enableDefaultSlf4jLoggingOfOutputData() {
+        addSlf4jLogMessageConsumer((logMessage, ctx) -> {
+            if (ctx.getLevel().equals(DEBUG)) {


this is anyway not very accurate, since this [debug] prefix is also not always added to debug logs

@mykola-mokhnach So what do you sugests instead? Should all be logged at INFO level? As it is now log messages with [debug] prefix is logged at DEBUG level. That is better than nothing if you ask me.

mykola-mokhnach · 2018-08-31T12:41:59Z

src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java

+        });
+    }
+
+    static Slf4jLogMessageContext parseSlf4jContextFromLogMessage(String logMessage) {


codacy does not like package-level visibility. Please add public

@mykola-mokhnach There is a big difference between public and package private. Making it public will make it part of the public API, which is not desired in this case.

I don't think we should make an implementation detail public just because codacy says so, or?

mykola-mokhnach · 2018-08-31T12:42:51Z

src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java

+     * 
+     */
+    public void addLogMessageConsumer(Consumer<String> consumer) {
+        addOutPutStream(new OutputStream() {


I'm not following this comment? addOutPutStream(...) is the name of an already existing method.

There is a typo in this word

@mykola-mokhnach
I'm still not following what this has to do with this PR?
As I said the addOutPutStream(...) method is already existing. Changing its name would be a breaking change.

then yes, it is better to keep it as is if it was there

mykola-mokhnach · 2018-08-31T12:45:02Z

src/test/java/io/appium/java_client/service/local/AppiumDriverLocalServiceTest.java

+        assertLoggerContext(DEBUG, "appium.service.xcuitest", 
+            "[debug] [XCUITest] Xcode version set to 'x.y.z' ");
+        assertLoggerContext(DEBUG, "appium.service.jsonwpproxy", 
+            "[debug] [JSONWP Proxy] Proxying [GET /status] to [GET http://localhost:18218/status] with no body");


How would you parse messages with timestamps like 2018-08-31 08:17:13:741 - info: [debug] [JSONWP Proxy] Matched '/element' to command name 'findElement' ?

as mentioned in javadoc. this feature is not supported when --log-timestamp is enabled.

from javadoc:
NOTE2: it is required that {@code --log-timestamp} server flag is {@code false}.

@mykola-mokhnach ^

mykola-mokhnach · 2018-08-31T14:03:09Z

src/test/java/io/appium/java_client/service/local/ServerBuilderTest.java

+        List<String> log = new ArrayList<>();
+        service = buildDefaultService();
+        service.clearOutPutStreams();
+        service.addLogMessageConsumer(log::add);


should we also have a possibility to remove a consumer?

Essentially a consumer in this case is an OutputStream (as added with addOutPutStream(...) method). So consumers can be removed with the clearOutPutStreams() method.

mykola-mokhnach · 2018-08-31T14:04:10Z

src/main/java/io/appium/java_client/service/local/AppiumDriverLocalService.java

+     *            BiConsumer block to be executed when a log message is
+     *            available.
+     */
+    public void addSlf4jLogMessageConsumer(


I find it useful to return self instance from such methods, so one can chain them

I agree it is nice to return self to chain method calls. But no other methods in this class does that, so I figured to follow same pattern as other methods. Would be strange if only this method returned self.

alexander-poulikakos · 2018-08-31T14:17:11Z

I just realized these methods does not do a null check of given arguments. Will fix that.

addSlf4jLogMessageConsumer(...)
addLogMessageConsumer(...)

alexander-poulikakos · 2018-09-07T09:06:35Z

Will this be merged?

alexander-poulikakos added 6 commits August 30, 2018 17:13

Add support for logging appium server output data through SLF4J.

385e81e

Format changes

97981ee

minor changes

294bcf6

format changes

f93ed2e

added dependency to alf4j-api

9455c34

name changes

a27cd6f

mykola-mokhnach reviewed Aug 31, 2018

View reviewed changes

alexander-poulikakos added 5 commits August 31, 2018 11:39

Fixed review comments.

954cc60

Fixed indentation.

aec7b55

more indentation fixes.

7268231

Fixed javadoc errors.

606322e

more javadoc fixes.

0739c0c

appium deleted a comment Aug 31, 2018

appium deleted a comment from alexander-poulikakos Aug 31, 2018

mykola-mokhnach reviewed Aug 31, 2018

View reviewed changes

added null check of method arguments.

0ecaa89

appium deleted a comment Aug 31, 2018

Added @VisibleForTesting annotation to avoid codacy warning.

e3ac85b

appium deleted a comment Sep 3, 2018

mykola-mokhnach approved these changes Sep 4, 2018

View reviewed changes

SrinivasanTarget approved these changes Sep 7, 2018

View reviewed changes

SrinivasanTarget merged commit a873737 into appium:master Sep 7, 2018

alexander-poulikakos mentioned this pull request Sep 10, 2018

Allow log configuration #414

Closed

Add SLF4J logging support for Appium local service #1014

Add SLF4J logging support for Appium local service #1014

Conversation

alexander-poulikakos commented Aug 31, 2018

Change list

Types of changes

Details

mykola-mokhnach commented Aug 31, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

alexander-poulikakos commented Aug 31, 2018

alexander-poulikakos commented Aug 31, 2018

mykola-mokhnach commented Aug 31, 2018

alexander-poulikakos commented Aug 31, 2018

mykola-mokhnach commented Aug 31, 2018

alexander-poulikakos commented Aug 31, 2018

Choose a reason for hiding this comment

alexander-poulikakos Aug 31, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

alexander-poulikakos commented Aug 31, 2018

alexander-poulikakos commented Sep 7, 2018

alexander-poulikakos Aug 31, 2018 •

edited

Loading