Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(adam): fix since options in LogcatRequest #83

Merged
merged 7 commits into from
Jul 4, 2022

Conversation

WindSekirun
Copy link
Contributor

@WindSekirun WindSekirun commented Jul 2, 2022

As describe in https://developer.android.com/studio/command-line/logcat#options, -t option accepts time string instead seconds.

This PR change contains using time string (MM-dd HH:mm:ss.SSS, ex, '01-26 20:52:41.820') instead time string. also add E2E Test to validate this feature

  • Change SyncLogcatRequest / ChanneledLogcatRequest
  • Change exists unit test
  • Write E2E Test (LogcatE2ETest)

@Malinskiy
Copy link
Owner

Hey @WindSekirun, thanks for submitting this,

While the documentation is correct, the implementation of logcat binary accepts the UNIX timestamp for a long time:
https://cs.android.com/android/platform/superproject/+/master:system/logging/logcat/logcat.cpp;drc=85cd3b25c31a8d98e4a371c5a6d1792a9b0c9d88;l=433

This is the commit that added this functionality: https://cs.android.com/android/_/android/platform/system/logging/+/4d0473f77bc0dab6280a47d3f01b7535d4a13820

Is this PR intended to fix a problem that it doesn't work for some devices, or it's intended to be an alignment between documentation and implementation?

There is already a behaviour that basically works here and I would like to keep it, but at the same time if you want to support different formatting here - we can implement an option to enhance the behaviour rather than replace it. WDYT?

@WindSekirun
Copy link
Contributor Author

@Malinskiy

Originally, the intention of this PR was to fix problem that doesn't work for some devices. While developing our own test runner system, i found some Samsung devices doesn't work for 'timestamp' format. (example, SM-G998N, F771N, F916N, F926N)

As i understand it, in logcat.cpp, 'date string' format seems to have a bit more priority. So, we can implement boolean property or add sealed class to define supporting time format like below. However, I think adding a boolean would be good for simplicity.

sealed class Since(val text: String) {

    class DateString(instant: Instant) : Since("'${sinceFormatter.format(instant)}'")

    class TimeStamp(instant: Instant) : Since("${instant.toEpochMilli()}.0")
}

@Malinskiy
Copy link
Owner

The sealed class works for me. Alternatively, you can use an enum with a parameter. I will merge either of those two options

@WindSekirun
Copy link
Contributor Author

@Malinskiy added 'LogcatSinceFormat' class and add some unit test.

@WindSekirun
Copy link
Contributor Author

I found that the test was failing because of a timezone issue. It is being edited.

@Malinskiy
Copy link
Owner

@WindSekirun can you please double check this actually works on a real device both in UTC and in a different timezone before merging? thanks!

@codecov
Copy link

codecov bot commented Jul 3, 2022

Codecov Report

Merging #83 (a885073) into master (86bea1f) will increase coverage by 0.08%.
The diff coverage is 93.33%.

@@             Coverage Diff              @@
##             master      #83      +/-   ##
============================================
+ Coverage     81.12%   81.21%   +0.08%     
- Complexity      715      717       +2     
============================================
  Files           138      139       +1     
  Lines          3057     3066       +9     
  Branches        507      507              
============================================
+ Hits           2480     2490      +10     
+ Misses          314      313       -1     
  Partials        263      263              
Flag Coverage Δ
integration 64.12% <60.00%> (+0.56%) ⬆️
unit 72.24% <93.33%> (+0.01%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files Coverage Δ
...skiy/adam/request/logcat/ChanneledLogcatRequest.kt 94.64% <75.00%> (ø)
...malinskiy/adam/request/logcat/LogcatSinceFormat.kt 100.00% <100.00%> (ø)
...malinskiy/adam/request/logcat/SyncLogcatRequest.kt 84.21% <100.00%> (+5.26%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 86bea1f...a885073. Read the comment docs.

@WindSekirun
Copy link
Contributor Author

WindSekirun commented Jul 3, 2022

@Malinskiy

Thanks for pointing which i missed!

I've figured out that if the real machine is using a different timezone than the host computer, it will work incorrectly.

I found that Instant doesn't contain Timezone information, so I changed PR with below.

  • Change 'enum class' to 'sealed class' in LogcatSinceFormat.
    • In the case of DateString and DateStringYear types, it is necessary to pass the timezone of the device correctly. (Timestamp, on the other hand, doesn't. so sealed classes will explain this well. but i have concern it is some kinds of 'breaking change'.)
  • Replace 'since' type with 'LogcatSinceFormat'

Fortunately, we can get timezone information with GetSinglePropRequest.

Through LogcatE2ETest, the following case was verified to be successful. (both client is real device)

  • Host: Asia/Seoul, Client: Asia/Seoul
  • Host: Asia/Seoul, Client: America/Los_Angeles
  • Host: Asia/Seoul, Client: UTC

@Malinskiy
Copy link
Owner

For some reason API 29 failed the test with:

testChanneledRequest
java.lang.AssertionError: 
Expected: <true>
     but: was <false>
	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:8)
	at com.malinskiy.adam.integration.LogcatE2ETest$testChanneledRequest$1.invokeSuspend(LogcatE2ETest.kt:103)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTaskKt.resume(DispatchedTask.kt:234)
	at kotlinx.coroutines.DispatchedTaskKt.dispatch(DispatchedTask.kt:166)
	at kotlinx.coroutines.CancellableContinuationImpl.dispatchResume(CancellableContinuationImpl.kt:397)
	at kotlinx.coroutines.CancellableContinuationImpl.resumeImpl(CancellableContinuationImpl.kt:431)
	at kotlinx.coroutines.CancellableContinuationImpl.resumeImpl$default(CancellableContinuationImpl.kt:420)
	at kotlinx.coroutines.CancellableContinuationImpl.resumeUndispatched(CancellableContinuationImpl.kt:518)
	at kotlinx.coroutines.EventLoopImplBase$DelayedResumeTask.run(EventLoop.common.kt:494)
	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:279)
	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
	at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
	at com.malinskiy.adam.integration.LogcatE2ETest.testChanneledRequest(LogcatE2ETest.kt:81)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at com.malinskiy.adam.rule.AdbDeviceRule$apply$1.evaluate(AdbDeviceRule.kt:67)
	at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutStatement$evaluate$$inlined$runWithTimeoutDumpingCoroutines$1.call(CoroutinesTimeoutImpl.kt:83)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.lang.Thread.run(Thread.java:829)

@WindSekirun
Copy link
Contributor Author

It looks like getting logs that are before few milliseconds of the specified time. if remove 5 seconds from zonedInstant, it would be fine.

(I found that it reproduced intermittently when I tested it immediately after changing the timezone on a real device)

@Malinskiy Malinskiy merged commit ee99146 into Malinskiy:master Jul 4, 2022
@Malinskiy
Copy link
Owner

Awesome work! I really appreciate your time

@WindSekirun WindSekirun deleted the fix/logcat-since-string branch July 4, 2022 01:57
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants