Gold flake: user does not have permission to list objects

@Piinks

02:51 +1116 ~1: /tmp/flutter sdk/packages/flutter/test/material/radio_test.dart: Radio ink ripple is displayed correctly                                                                               
══╡ EXCEPTION CAUGHT BY FLUTTER TEST FRAMEWORK ╞════════════════════════════════════════════════════
The following _Exception was thrown while running async test code:
Exception: Unexpected Gold tryjobAdd failure.
Tryjob execution for golden file test material.radio.ink_ripple.png failed for
a reason unrelated to pixel comparison.

Debug information for Gold:
stdout: Given image with hash 2887f99f7ebb5fda0580e7a4afa32f21 for test material.radio.ink_ripple
Expectation for test: 2887f99f7ebb5fda0580e7a4afa32f21 (positive)
Expectation for test: e0700bcc1503b6e84be54f433dea6ae9 (positive)

stderr: ERROR: logging before flag.Parse: I0131 21:03:52.169569    7736 exec.go:221] exec.go:221
Executing 'gsutil cp /tmp/flutter
sdk/bin/cache/pkg/skia_goldens7708/packages/flutter/test/material/temp/dm.json
gs://skia-gold-flutter/trybot/dm-json-v1/2020/01/31/21/f202972e4b8e923e0c9b938943bb8545c2cc54b9/6530858593026048/1580504632/dm-1580504632169051403.json'
(where gsutil is /usr/bin/gsutil)
Error running command: ''Error uploading JSON file to GCS path
skia-gold-flutter/trybot/dm-json-v1/2020/01/31/21/f202972e4b8e923e0c9b938943bb8545c2cc54b9/6530858593026048/1580504632/dm-1580504632169051403.json:
running gsutil. Got output
AccessDeniedException: 403 [email protected] does not have
storage.objects.list access to skia-gold-flutter.

: Command exited with exit status 1: gsutil cp /tmp/flutter
sdk/bin/cache/pkg/skia_goldens7708/packages/flutter/test/material/temp/dm.json
gs://skia-gold-flutter/trybot/dm-json-v1/2020/01/31/21/f202972e4b8e923e0c9b938943bb8545c2cc54b9/6530858593026048/1580504632/dm-1580504632169051403.json.
At gcs.go:101 gcs.go:77 gcs.go:66 goldclient.go:422 goldclient.go:346 errgroup.go:57
asm_amd64.s:1357. At goldclient.go:423 goldclient.go:346 errgroup.go:57 asm_amd64.s:1357''

When the exception was thrown, this was the stack:
#0      SkiaGoldClient.tryjobAdd (package:flutter_goldens_client/skia_client.dart:371:9)
<asynchronous suspension>
#1      _AuthorizedFlutterPreSubmitComparator.compare (package:flutter_goldens/flutter_goldens.dart:374:23)
<asynchronous suspension>
#2      MatchesGoldenFile.matchAsync.<anonymous closure> (package:flutter_test/src/_matchers_io.dart:82:57)
<asynchronous suspension>
#3      AutomatedTestWidgetsFlutterBinding.runAsync.<anonymous closure> (package:flutter_test/src/binding.dart:924:22)
#6      AutomatedTestWidgetsFlutterBinding.runAsync (package:flutter_test/src/binding.dart:922:26)
#7      MatchesGoldenFile.matchAsync (package:flutter_test/src/_matchers_io.dart:72:20)
#9      MatchesGoldenFile.matchAsync (package:flutter_test/src/_matchers_io.dart:52:28)
#10     _expect (package:test_api/src/frontend/expect.dart:116:26)
#11     expectLater (package:test_api/src/frontend/expect.dart:75:5)
#12     expectLater (package:flutter_test/src/widget_tester.dart:385:10)
#13     main.<anonymous closure> (file:///tmp/flutter%20sdk/packages/flutter/test/material/radio_test.dart:281:11)
#26     AutomatedTestWidgetsFlutterBinding.runTest.<anonymous closure> (package:flutter_test/src/binding.dart:1102:17)
#28     AutomatedTestWidgetsFlutterBinding.runTest.<anonymous closure> (package:flutter_test/src/binding.dart:1090:35)
(elided 31 frames from class _FakeAsync, dart:async, dart:async-patch, and package:stack_trace)
════════════════════════════════════════════════════════════════════════════════════════════════════

02:51 +1116 ~1 -1: /tmp/flutter sdk/packages/flutter/test/material/popup_menu_test.dart: PopupMenu positioning                                                                                         
02:51 +1116 ~1 -1: /tmp/flutter sdk/packages/flutter/test/material/radio_test.dart: Radio ink ripple is displayed correctly [E]                                                                        
  Test failed. See exception logs above.
  The test description was: Radio ink ripple is displayed correctly

https://cirrus-ci.com/task/6530858593026048

/cc @Piinks

@kjlubick

cc/ @kjlubick
It looks like it is trying to authenticate with an unknown service account ([email protected]?). I don't know why it would be doing this. Could Cirrus be providing the wrong service account?

I saw this for the first time the other day on #49334. It did not reproduce on that PR or any other.

This was my PR, so it should have had access to whatever encrypted credentials we have.

This seems to be happening on my most recent PR as well: #49913

Cirrus task that is failing: https://cirrus-ci.com/task/5942114139766784

Yeah, it would say 'ENCRYPTED' if it were a permissions issue, but that service account is not the one associated with Gold. I have no idea where it came from or why it is trying to authenticate with that account. 🤔

https://api.cirrus-ci.com/v1/task/5558371025682432/logs/main.log seems similar

527266040592-compute might be a default service-account for the project with # 527266040592. Perhaps the logic that loads in the service account to Cirrus needs examination?

For debugging, maybe print out the hash of the service account file and compare good runs to bad runs?

@kjlubick

@kjlubick these runs generally succeed on a second try. Cirrus is always giving us the same account. Could this be a quota issue?

Hang on, I see the error message says goldctl is using gsutil (which is probably using the wrong service account). gsutil is not meant for production usage. Please check that you are properly calling goldctl auth and specifying a service account every time. Otherwise, goldctl falls back to using gsutil.

@fkorotkov

cc/ @fkorotkov in case this may be a Cirrus issue.

Here's what I can tell thus far

This so far has only been reported on linux shards - framework_tests-libraries-linux and framework_tests-widgets-linux
This is happening with the _AuthorizedFlutterPreSubmitComparator, which is only used when the service account is available from Cirrus.
The service account comes from an encrypted environment variable on Cirrus called GOLD_SERVICE_ACCOUNT
- If the service account variable exists, but is empty, it would throw during auth.
- If the service account is still encrypted due to user permissions, it would use the _UnauthorizedFlutterPresubmitComparator (used for empty auth, does not run tryjobs)
As reported by @dnfield, re-running the test shard may or may not reproduce the issue, sometimes have no issue at all on a re-run.
These flakes have all happened after adding a tryjob. Other calls (auth and init) aren't throwing before that point like I would expect if there was an auth issue, see call flow below.
Furthermore, this does not appear to happen on every tryjob that is executing on that shard. Some tryjobs succeed in executing, while only a few are flaking.
- In some reports only one tryjob flakes, while in others as many as 7 flake.

First, auth is called

Will throw for empty service account

goldctl auth --service-account serviceAccount.json --work-dir $workDirectory

Will throw if non-zero exit code returns from auth
Based on logs, this all appears successful ✅

Then imgtest init for tryjob

Will throw if there are any null arguments provided for this process

goldctl imgtest init
--instance flutter 
--work-dir $workDirectory
--commit $commitHash
--keys-file $keys
--failure-file $failures
--passfail
--crs github
--cis cirrus
--jobid $cirrusTaskID
--patchset_id $commitHash

Will throw for non-zero exit code from imgtest init
Based on logs, this all appears successful ✅

Finally imgtest add to add the tryjob

goldctl imgtest add
--work-dir $workDirectory
--test-name $testName
--png-file $goldenFile

Will throw for non-exit code, which is where this is happening. ☠️

I'll see about adding more logging here if it can be helpful to further diagnose. 🤒 Let me know what ya'll think about where along this path I can get more helpful information.

There's at least one report of this flake happening after the revert, but it's not super clear to me yet what happened there. Let's keep an eye on it today - if it's still happening we should revert the revert.

Do you have a PR/task/log we can see where it is still happening?

https://cirrus-ci.com/task/6059363425058816?command=main#L1268

Another instance https://cirrus-ci.com/task/5085804800245760?command=main#L927

Is it possible some reoccurrences could be from branches that need to be updated?

@Piinks

@Piinks: I just checked, and both have the reverted version of the dockerfile :/

From this log: https://api.cirrus-ci.com/v1/task/6064140468879360/logs/main.log

It looks like this is happening when auth_opt.json (created by goldctl during auth) already exists. The SkiaClient checks to see if it is already there so it won't re-authenticate if unnecessary.

// in SkiaClient.auth
Skia Client is already authorized.
auth_opt.json: 
{
  "Luci":false,
  "ServiceAccount":"",
  "GSUtil":true
}

However, this does not happen every time, as there are other cases where everything seems to be ok:

// in SkiaClient.auth
Skia Client is already authorized.                                                                                                    
{
  "Luci":false,
  "ServiceAccount":"/tmp/flutter sdk/bin/cache/pkg/skia_goldens3735/packages/flutter/test/widgets/serviceAccount.json",
  "GSUtil":false
}

The GOLD_SERVICE_ACCOUNT seems to also be ok, confirmed the service account is present with the right information in every test (checked client_email).

I think I know what this is now. 🎉

To solve #46687, #47551 added the empty auth option for goldctl so we could use the check feature. When using empty auth, no tryjobs are run/nothing is done that actually requires authentication.
I'm guessing that empty auth would create an auth_opt.json file like the first mentioned above where GSUtil:true

These files are all created in randomly generated directories to maintain thread safety.

If they are being cached, which I think they are (the 🐞 ), then future test runs that randomly choose the same directory that need to be authenticated don't because they see that the file is there and assume it's already set up, and therefore end up using gsutil.

Yep, that sounds like it would be it - I guess the solution is to clean up the temporary Gold folder after you are done?

@Piinks

@Piinks thanks for tracking this down and fixing!

This thread has been automatically locked since there has not been any recent activity after it was closed. If you are still experiencing a similar issue, please open a new bug, including the output of flutter doctor -v and a minimal reproduction of the issue.

Navigation Menu

Repository navigation

Gold flake: user does not have permission to list objects #49917

15 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Gold flake: user does not have permission to list objects #49917

Description

Activity

Piinks commented on Jan 31, 2020

dnfield commented on Jan 31, 2020

shihaohong commented on Jan 31, 2020

Piinks commented on Jan 31, 2020

dnfield commented on Feb 1, 2020

kjlubick commented on Feb 3, 2020

dnfield commented on Feb 3, 2020

kjlubick commented on Feb 3, 2020

Piinks commented on Feb 3, 2020

15 remaining items

dnfield commented on Feb 4, 2020

Piinks commented on Feb 4, 2020

a14n commented on Feb 4, 2020

christopherfujino commented on Feb 4, 2020

Piinks commented on Feb 4, 2020

christopherfujino commented on Feb 4, 2020

Piinks commented on Feb 4, 2020

Piinks commented on Feb 4, 2020

kjlubick commented on Feb 5, 2020

christopherfujino commented on Feb 5, 2020

github-actions commented on Aug 13, 2021

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions