1213032 - consider the usefulness of talos tcheck2

Status: RESOLVED WORKSFORME

(Testing :: Talos, defect)

Description

[Joel Maher ( :jmaher ) (UTC -8)]

I am looking at tcheck2 as it showed up as regressions/improvements a few random times while analyzing other regressions.  Here is the graph over time:

http://graphs.mozilla.org/graph.html#tests=[[201,63,29]]&sel=1440042946605.8838,1443287969861.6978,1.4210854715202004e-14,50.00000000000001&displayrange=90&datatype=geo

What is interesting is that on September 3rd we go from something that is normal to a very noisy distribution.  This distribution makes it hard to determine a regression.

I believe the issue is related to:
https://bugzilla.mozilla.org/show_bug.cgi?id=1107372

We don't have any other checkerboarding metrics, so this test has a lot of value.  But the problem is that it is causing a lot of randomization for us and has reduced its usefulness with the large volume of noise it produces.

As we move to autophone this quarter we should look at this carefully and decide what we want to do with it.

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

:kats, you have a lot of good insight into this test, do you have some thoughts here?

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

Randall, I understand you are working on panning and zooming- it would be nice to get your input on how we can ensure tcheck2 is working and ensure it is useful with the changes you are making

Comment 3

[Geoff Brown [:gbrown]]

Logcats for tcheck2 now have frequent GeckoDynamicToolbarAnimator messages:

13:11:56     INFO -  10-15 13:10:53.171 V/GeckoDynamicToolbarAnimator( 3007): Got vertical translation 0.0
13:11:56     INFO -  10-15 13:10:53.187 V/RobocopMotionEventReplayer( 3007): Injecting MotionEvent { action=ACTION_MOVE, id[0]=0, x[0]=836.17194, y[0]=466.27084, toolType[0]=TOOL_TYPE_UNKNOWN, buttonState=0, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1023149, downTime=1023101, deviceId=0, source=0x1002 }
13:11:56     INFO -  10-15 13:10:53.187 V/GeckoDynamicToolbarAnimator( 3007): Got vertical translation 0.0
13:11:56     INFO -  10-15 13:10:53.203 V/RobocopMotionEventReplayer( 3007): Injecting MotionEvent { action=ACTION_MOVE, id[0]=0, x[0]=829.07074, y[0]=434.23807, toolType[0]=TOOL_TYPE_UNKNOWN, buttonState=0, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1023168, downTime=1023101, deviceId=0, source=0x1002 }
13:11:56     INFO -  10-15 13:10:53.203 V/GeckoDynamicToolbarAnimator( 3007): Got vertical translation -32.0
13:11:56     INFO -  10-15 13:10:53.226 V/RobocopMotionEventReplayer( 3007): Injecting MotionEvent { action=ACTION_MOVE, id[0]=0, x[0]=825.52014, y[0]=397.86188, toolType[0]=TOOL_TYPE_UNKNOWN, buttonState=0, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1023188, downTime=1023101, deviceId=0, source=0x1002 }
13:11:56     INFO -  10-15 13:10:53.226 V/GeckoDynamicToolbarAnimator( 3007): Got vertical translation -37.0
13:11:56     INFO -  10-15 13:10:53.242 V/RobocopMotionEventReplayer( 3007): Injecting MotionEvent { action=ACTION_MOVE, id[0]=0, x[0]=825.52014, y[0]=358.771, toolType[0]=TOOL_TYPE_UNKNOWN, buttonState=0, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1023207, downTime=1023101, deviceId=0, source=0x1002 }
13:11:56     INFO -  10-15 13:10:53.242 V/GeckoDynamicToolbarAnimator( 3007): Got vertical translation -39.0
13:11:56     INFO -  10-15 13:10:53.273 V/RobocopMotionEventReplayer( 3007): Injecting MotionEvent { action=ACTION_MOVE, id[0]=0, x[0]=827.2955, y[0]=324.5665, toolType[0]=TOOL_TYPE_UNKNOWN, buttonState=0, metaState=0, flags=0x0, edgeFlags=0x0, pointerCount=1, historySize=0, eventTime=1023226, downTime=1023101, deviceId=0, source=0x1002 }
13:11:56     INFO -  10-15 13:10:53.273 V/GeckoDynamicToolbarAnimator( 3007): Got vertical translation -34.0

I don't know if this is expected, or if it is significant wrt the noise. I mention it because I don't remember seeing these messages in the past (months ago).

Comment 4

[Randall Barker [:rbarker]]

(In reply to Joel Maher (:jmaher) from comment #2)
> Randall, I understand you are working on panning and zooming- it would be
> nice to get your input on how we can ensure tcheck2 is working and ensure it
> is useful with the changes you are making

Currently I'm working to enable C++APZ in Fennec. I've mostly been working on the event handling so am not really able to answer any thing about rendering and checker boarding. Hopefully :kats will have better input when he is back from PTO.

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

:rbarker, your changes will probably affect this test greatly and we should take this opportunity to ensure we are actually testing for checkerboarding when your APZ patch(es) land.

:gbrown, your message about seeing GeckoDynamicToolbarAnimator is interesting.  Does this mean that we are showing the toolbar often during the course of this test?  Any thoughts on how to reduce GeckoDynamicToolbarAnimator from showing up?

Comment 6

[Geoff Brown [:gbrown]]

The most common GeckoDynamicToolbarAnimator message I see is "Got vertical translation", from onInterceptTouchEvent(); that function does some calculations, but isn't strongly associated with animation or any obviously expensive operation. 

I am more concerned with calls to animateToolbar(). In http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/[e-mail]-09d207079200/try-android-api-11/try_panda_android_test-remote-trobocheck2-bm100-tests1-panda-build87.txt.gz I suppressed all GeckoDynamicToolbarAnimator logs except for "Requested toolbar animation to translation", in animateToolbar(). It looks like there are a few dozen calls to animateToolbar() over the course of the test, but they all have "Requested toolbar animation to translation 0.0", so I'm not sure they are responsible for a lot of work. I'm not sure, but I think everything may be working as expected here.

Comment 7

[Joel Maher ( :jmaher ) (UTC -8)]

until we determine what is useful to measure here, the rck3 test (ported version to autophone) will be on hold. Right now we don't have stable numbers on panda boards or on autophone (nexus-s) to take this test seriously.

Comment 8

[Kartikaya Gupta (email:[e-mail])]

I think the code used to "measure" checkerboarding in this test will no longer be valid upon switching to APZ, so the test will need to be largely rewritten after the switch to APZ. I still like the idea of having a canned input sequence and feeding that to the device and recording the resulting checkerboard though, and I think there is value in this style of test. My suggestion is that we disable this test as part of turning on the C++ APZ on Fennec, and write a new test to record checkerboarding better for when the C++ APZ is enabled.

Comment 9

[Joel Maher ( :jmaher ) (UTC -8)]

:rbarker, when is the timeline for APZ?

Comment 10

[Randall Barker [:rbarker]]

(In reply to Joel Maher (:jmaher) from comment #9)
> :rbarker, when is the timeline for APZ?

We hope to have in on in nightly in the next few weeks and have it start riding the trains by end of this quarter.

The current gating issue for nightly is passing try.

Comment 11

[Joel Maher ( :jmaher ) (UTC -8)]

can we retitle this or close it?  we have disabled tcheck2 and now that APZ is landed (yay), we need a more relevant and accurate test (tcheck3).