microsoft / windows-dev-center-vsts-extension

Visual Studio Team Services (VSTS) extension for performing continuous delivery to the Windows Dev Center store from your automated CI builds
Other
42 stars 18 forks source link

Submission takes about 12-16 hours to reflect the changes made by the Build Task #58

Closed DerGary closed 6 years ago

DerGary commented 6 years ago

It takes a long time till the Submission is submitted:

After the build task runs, it takes about 12 to 16 hours to see the changes it should have made to the new submission and to finally submit it. In July it did not take so long. Manuell Submissions can be submitted instantly.

Here are my Settings:

image

This is the resulting Submission:

you can see that it is not submitted because the button is still active and the package should be 3.5.4 but is still the old 3.4.5: image

The resulting Submission the next day:

image

Log File:

Here is the log file with debug enabled, I censored some ids just to be save.

2018-08-22T12:59:26.9353672Z ##[debug]Evaluating condition for step: 'Publish $(System.ArtifactsDirectory)\**\Test\*.appxupload'
2018-08-22T12:59:26.9356059Z ##[debug]Evaluating: succeeded()
2018-08-22T12:59:26.9356675Z ##[debug]Evaluating succeeded:
2018-08-22T12:59:26.9357573Z ##[debug]=> True
2018-08-22T12:59:26.9358358Z ##[debug]Result: True
2018-08-22T12:59:26.9359282Z ##[section]Starting: Publish $(System.ArtifactsDirectory)\**\Test\*.appxupload
2018-08-22T12:59:26.9367443Z ==============================================================================
2018-08-22T12:59:26.9367951Z Task         : Windows Store - Publish
2018-08-22T12:59:26.9368295Z Description  : Publish your app to the Windows Store
2018-08-22T12:59:26.9368593Z Version      : 0.10.25
2018-08-22T12:59:26.9369003Z Author       : Microsoft Corporation
2018-08-22T12:59:26.9369265Z Help         : 
2018-08-22T12:59:26.9369645Z ==============================================================================
2018-08-22T12:59:27.3877701Z ##[debug]agent.workFolder=C:\Tools\agent2\_work
2018-08-22T12:59:27.3983288Z ##[debug]loading inputs and endpoints
2018-08-22T12:59:27.3995760Z ##[debug]loading ENDPOINT_AUTH_384*******352
2018-08-22T12:59:27.4015412Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_384*******352_SERVICEPRINCIPALID
2018-08-22T12:59:27.4019729Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_384*******352_SERVICEPRINCIPALKEY
2018-08-22T12:59:27.4023178Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_384*******352_TENANTID
2018-08-22T12:59:27.4026278Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_384*******352_URL
2018-08-22T12:59:27.4029460Z ##[debug]loading ENDPOINT_AUTH_PARAMETER_SYSTEMVSSCONNECTION_ACCESSTOKEN
2018-08-22T12:59:27.4034490Z ##[debug]loading ENDPOINT_AUTH_SCHEME_384*******352
2018-08-22T12:59:27.4037677Z ##[debug]loading ENDPOINT_AUTH_SCHEME_SYSTEMVSSCONNECTION
2018-08-22T12:59:27.4040752Z ##[debug]loading ENDPOINT_AUTH_SYSTEMVSSCONNECTION
2018-08-22T12:59:27.4044185Z ##[debug]loading INPUT_APPID
2018-08-22T12:59:27.4050524Z ##[debug]loading INPUT_DELETEPACKAGES
2018-08-22T12:59:27.4055446Z ##[debug]loading INPUT_FORCE
2018-08-22T12:59:27.4058772Z ##[debug]loading INPUT_ISMANDATORYUPDATE
2018-08-22T12:59:27.4063756Z ##[debug]loading INPUT_MANDATORYUPDATEDIFFERHOURS
2018-08-22T12:59:27.4068277Z ##[debug]loading INPUT_METADATAPATH
2018-08-22T12:59:27.4071239Z ##[debug]loading INPUT_METADATAUPDATEMETHOD
2018-08-22T12:59:27.4074205Z ##[debug]loading INPUT_NAMETYPE
2018-08-22T12:59:27.4077346Z ##[debug]loading INPUT_NUMBEROFPACKAGESTOKEEP
2018-08-22T12:59:27.4083290Z ##[debug]loading INPUT_PACKAGEPATH
2018-08-22T12:59:27.4086991Z ##[debug]loading INPUT_SERVICEENDPOINT
2018-08-22T12:59:27.4089952Z ##[debug]loading INPUT_SKIPPOLLING
2018-08-22T12:59:27.4094653Z ##[debug]loading INPUT_UPDATEIMAGES
2018-08-22T12:59:27.4103841Z ##[debug]loaded 22
2018-08-22T12:59:28.3245917Z ##[debug]serviceEndpoint=384*******352
2018-08-22T12:59:28.3270261Z 384*******352 exists true
2018-08-22T12:59:28.3270928Z ##[debug]384*******352 exists true
2018-08-22T12:59:28.3276892Z ##[debug]force=true
2018-08-22T12:59:28.3279432Z ##[debug]metadataUpdateMethod=NoUpdate
2018-08-22T12:59:28.3282563Z ##[debug]updateImages=false
2018-08-22T12:59:28.3283436Z ##[debug]Agent.WorkFolder=C:\Tools\agent2\_work
2018-08-22T12:59:28.3286536Z ##[debug]skipPolling=true
2018-08-22T12:59:28.3290288Z ##[debug]deletePackages=true
2018-08-22T12:59:28.3301384Z ##[debug]numberOfPackagesToKeep=0
2018-08-22T12:59:28.3305172Z ##[debug]isMandatoryUpdate=false
2018-08-22T12:59:28.3308955Z ##[debug]packagePath=C:\Tools\agent2\_work\r11\a\**\Test\*.appxupload
2018-08-22T12:59:28.3312527Z ##[debug]Agent.ReleaseDirectory=C:\Tools\agent2\_work\r11\a
2018-08-22T12:59:28.3315304Z ##[debug]packagePath=C:\Tools\agent2\_work\r11\a\**\Test\*.appxupload
2018-08-22T12:59:28.4129273Z ##[debug]additionalPackages=null
2018-08-22T12:59:28.4133507Z ##[debug]nameType=AppId
2018-08-22T12:59:28.4136125Z ##[debug]appId=9NB***4M3
2018-08-22T12:59:28.4139676Z ##[debug]metadataPath=C:\Tools\agent2\_work\r11\a
2018-08-22T12:59:28.4150655Z ##[debug]App ID: 9NB***4M3
2018-08-22T12:59:28.4151353Z ##[debug]Endpoint: ***
2018-08-22T12:59:28.4151794Z ##[debug]Force delete: true
2018-08-22T12:59:28.4152236Z ##[debug]Metadata update type: 0
2018-08-22T12:59:28.4152708Z ##[debug]Update images: false
2018-08-22T12:59:28.4153196Z ##[debug]Metadata root: C:\Tools\agent2\_work\r11\a
2018-08-22T12:59:28.4153796Z ##[debug]Packages: C:/Tools/agent2/_work/r11/a/Reporting App UWP Master/Reporting App/3.5.4.0/Test/Freier.App.Reporting_3.5.4.0_x86_x64_bundle_Test.appxupload
2018-08-22T12:59:28.4154381Z ##[debug]skipPolling: true
2018-08-22T12:59:28.4154848Z ##[debug]deletePackages: false
2018-08-22T12:59:28.4155705Z ##[debug]numberOfPackagesToKeep: 0
2018-08-22T12:59:28.4156465Z ##[debug]isMandatoryUpdate: false
2018-08-22T12:59:28.4156978Z ##[debug]mandatoryUpdateDifferHours: null
2018-08-22T12:59:28.4166412Z Authenticating...
2018-08-22T12:59:28.4168444Z Authenticating with server...
2018-08-22T12:59:28.4179377Z ##[debug]Starting request with correlation id: eb5aad6*******bbc408
2018-08-22T12:59:28.7175320Z ##[debug]Finished request with correlation id: eb5aad6*******bbc408
2018-08-22T12:59:28.7186258Z Obtaining app information...
2018-08-22T12:59:28.7190369Z ##[debug]Getting app resource from ID 9NB***4M3
2018-08-22T12:59:28.7203159Z ##[debug]Starting request with correlation id: 48a15*****1a50
2018-08-22T12:59:35.0023746Z ##[debug]Finished request with correlation id: 48a15*****1a50
2018-08-22T12:59:35.0024531Z Deleting existing submission...
2018-08-22T12:59:35.0028457Z ##[debug]Deleting submission at ***/v1.0/my/applications/9NB***4M3/submissions/11****784
2018-08-22T12:59:35.0031568Z ##[debug]Starting request with correlation id: f6fbe7******dc102b98
2018-08-22T12:59:42.5568149Z ##[debug]Finished request with correlation id: f6fbe7******dc102b98
2018-08-22T12:59:42.5568719Z Creating submission...
2018-08-22T12:59:42.5570315Z ##[debug]Creating new submission
2018-08-22T12:59:42.5573913Z ##[debug]Starting request with correlation id: fe3822e0*****4cf0e520
2018-08-22T13:01:01.2793801Z ##[debug]Warnings occurred in request
2018-08-22T13:01:01.2795726Z ##[debug]  [SalesUnsupportedWarning]  The sales resource is no longer supported. To view or edit the sales data for this submission, use the Dev Center dashboard.
2018-08-22T13:01:01.2796983Z ##[debug]CorrelationId: f285b0*****370333799
2018-08-22T13:01:01.2797856Z ##[debug]Finished request with correlation id: fe3822e0*****4cf0e520
2018-08-22T13:01:01.2798385Z Submission https://developer.microsoft.com/en-us/dashboard/apps/9NB***4M3/submissions/1152*****8796 was created successfully
2018-08-22T13:01:01.2798826Z Deleting old packages...
2018-08-22T13:01:01.2823657Z ##[debug]Removing 3.4.5.0
2018-08-22T13:01:01.2824058Z Updating package delivery options...
2018-08-22T13:01:01.2826634Z ##[debug]Setting isMandatoryUpdate to false
2018-08-22T13:01:01.2829914Z Updating submission...
2018-08-22T13:01:01.2833070Z ##[debug]Adding metadata for new submission 1152*****8796
2018-08-22T13:01:01.2838593Z ##[debug]Adding 1 package(s)
2018-08-22T13:01:01.2847062Z ##[debug]Updating submission
2018-08-22T13:01:01.2854740Z ##[debug]Starting request with correlation id: 586b17****0daa9
2018-08-22T13:01:18.4501223Z ##[debug]Finished request with correlation id: 586b17****0daa9
2018-08-22T13:01:18.4502860Z Creating zip file...
2018-08-22T13:01:18.4505580Z ##[debug]Creating zip file
2018-08-22T13:01:18.4512381Z ##[debug]Adding package path C:/Tools/agent2/_work/r11/a/Reporting App UWP Master/Reporting App/3.5.4.0/Test/Freier.App.Reporting_3.5.4.0_x86_x64_bundle_Test.appxupload to zip as 0_Freier.App.Reporting_3.5.4.0_x86_x64_bundle_Test.appxupload
2018-08-22T13:01:18.4542961Z ##[debug]Checking for new images in listing de...
2018-08-22T13:01:18.4545291Z ##[debug]Checking for new images in listing en...
2018-08-22T13:01:24.6210501Z Uploading zip file...
2018-08-22T13:01:24.6216866Z ##[debug]Uploading zip file to https://ingestionpackagesprod1.blob.core.windows.net/ingestion/b5274****33239d?sv=2017-04-17&sr=b&sig=yayh***dqjpi84L%2BSTHjWpb55txbM%2BORHmGjs4KoT%2BE%3D&se=2018-08-23T13:15:49Z&sp=rwl
2018-08-22T13:01:30.1233012Z Successfully uploaded file!
2018-08-22T13:01:30.1237447Z Committing submission...
2018-08-22T13:01:30.1243904Z ##[debug]Committing submission
2018-08-22T13:01:30.1278148Z ##[debug]Starting request with correlation id: e3e8****43c15f
2018-08-22T13:01:42.3781302Z ##[debug]Finished request with correlation id: e3e8****43c15f
2018-08-22T13:01:42.3781892Z Skip polling option is checked. Skipping polling...
2018-08-22T13:01:42.3782442Z Click here https://developer.microsoft.com/en-us/dashboard/apps/9NB***4M3/submissions/1152*****8796 to check the status of the submission in Dev Center
2018-08-22T13:01:42.3786481Z ##[debug]System.DefaultWorkingDirectory=C:\Tools\agent2\_work\r11\a
2018-08-22T13:01:42.3928514Z ##[debug]Processed: ##vso[task.addattachment type=Distributedtask.Core.Summary;name=DevCenter;]C:\Tools\agent2\_work\r11\a\DevCenter.md
2018-08-22T13:01:42.3929915Z ##[debug]task result: Succeeded
2018-08-22T13:01:42.3932132Z ##[debug]Processed: ##vso[task.complete result=Succeeded;]Submission completed
2018-08-22T13:01:42.4212219Z ##[section]Finishing: Publish $(System.ArtifactsDirectory)\**\Test\*.appxupload

If you need any further Information I will be happy to provide it.

Greetings Gary

ChristopheLav commented 6 years ago

I have encountered this issue two days back: the submission API seems only to have a huge delay. About 12 hours are required to the submission process pass in certification state then publishing state. During the delay, I see the same state as you describe.

DerGary commented 6 years ago

@ChristopheLav I already waited around 18 Hours and nothing happened.

did the Package of your submission change after that time?

DerGary commented 6 years ago

hmm I'm Sorry you're right I just looked at the Submission I created yesterday and it changed, it now is in stated published and contains only the new package:

image

ChristopheLav commented 6 years ago

Nice 👍 But the delay is very weird - previously its take only a few minutes to see the update in progress.

DerGary commented 6 years ago

yes it's very weird, and I don't like the additional time that it takes to publish a new app.

Can someone from Microsoft look into this? I will change the Issue accordingly

elendil326 commented 6 years ago

Thanks for reporting this @DerGary . We engaged the Store team since yesterday. My apologies for not providing an update earlier. The investigation is still ongoing. Some changes have already been deployed to improve the time of the submissions, but wok is still in progress for a definitive fix.

Feel free to update this issue if no improvement is seen yet.

ChristopheLav commented 6 years ago

I have submitted last night three updates (two flights and one release) and the time of the submissions are not improved like you say. All are blocked in « commit started » state since more than 15 hours 😕

Edit: 30 hours later, nothing has changed. So, your fix has increase the previous delay! No improvement here. I will open a support ticket… And, as usual, you have not communicate the issue in your users (no banner in Dev Center). Not the first time with the API.

jmvillagra commented 6 years ago

Same thing here... the whole thing is broken. Any estimates when everything will be working again? This broke our CI environment...

sebastianzolg commented 6 years ago

Same issue here! Please note that you can edit the submission anyway and be able to submit it to store manually again. I did so on the weekend when I saw that behaviour. The result is that I broke the whole thing and people no longer be able to download the app from store. Something gone completely wrong. So I would advise anybody to be careful with the pending submission. DO NOT MODIFY or you might face the same thing.

I opened a support ticket today with Microsoft. I pointed to this GitHub issue and asked for a response as well.

DerGary commented 6 years ago

Same here, added a new submission through the release task yesterday and it is still not submitted.

DerGary commented 6 years ago

Submission created: 28.08.18 14:40 Email that submission was processed: 30.08.18 02:53 so it took about 36 Hours

elendil326 commented 6 years ago

This issue has been resolved according to initial tests and the Store team. Please comment or re-open the issue if you are still experiencing issues with this.

DerGary commented 6 years ago

@elendil326 I created a Release on 31th of August that got live yesterday (11th of September) image

image

So it's definetly not fixed, It even seems a lot worse.

elendil326 commented 6 years ago

@DerGary during the stabilization period, some submissions remained stuck. It seems the submission you mention above was created before the issue was fixed. Let me know if a submission post 9/04 has been stuck and I can follow up with the Store team on why it is still affected.

DerGary commented 6 years ago

@elendil326 I created a release yesterday 9/20 at around 12 o'clock that was processed completely 9/21 at around 14 o'clock so it took about 26 Hours. I don't know if this was due to API Issues or app certification that took so long. But prior to this issue it normally took about 3-4 Hours to be processed completely including the certification