Jumoo / uSync.Complete.Issues

Public Issue tracker and roadmap for uSync.Complete
https://jumoo.co.uk/usync/complete/
2 stars 1 forks source link

Error while processing Push - (export/Push/0/) - Upload failed #192

Closed BarryFogarty closed 1 year ago

BarryFogarty commented 1 year ago

Describe the bug When pushing an update to a target server, uSync successfully uploads the file to its App_Data folder, but the following response is received by the final POST to /umbraco/backoffice/uSync/uSyncPublisherApi/PerformAction

{
  "id": "fb5b8af7-277b-495d-b156-18ebd5545309",
  "processComplete": false,
  "success": false,
  "message": null,
  "error": {
    "message": "Upload failed",
    "title": "Error while processing Push - (export/Push/0/)",
    "action": "export",
    "stepIndex": 4,
    "stepName": "Push",
    "pageNumber": 0,
    "className": "<UploadFile>d__11",
    "method": "MoveNext",
    "stackTrace": "   at uSync.Publisher.Publishers.SyncPublisherBase.<UploadFile>d__11.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()\r\n   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n   at uSync.Publisher.Publishers.SyncRealtimePublisher.<PushToServer>d__25.MoveNext()\r\n--- End of stack trace from previous location where exception was thrown ---\r\n   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()\r\n   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n   at uSync.Publisher.Controllers.uSyncPublisherApiController.<PerformAction>d__10.MoveNext()"
  },
  "actions": null,
  "actionComplete": false,
  "nextAction": "",
  "nextFolder": null,
  "stepIndex": 0,
  "nextPage": 0,
  "items": null,
  "progress": null
}

Version (please complete the following information):

To Reproduce Steps to reproduce the behavior:

  1. Push a simple content page to a target server
  2. Uncheck all additional options (Include children, media, files, dependencies etc)
  3. Click Continue
  4. See error screenshots

screenshot-sp-641 internal gibedigital com-2022 12 06-10_48_23

screenshot-sp-641 internal gibedigital com-2022 12 06-10_48_55

BarryFogarty commented 1 year ago

NB I have enabled verbose logging on the server, and I can see it receives the file ([GetFileFromRequest] [PushPack] debug messages), verifies the authentication token, and ends in a log message e.g. Content Stream 1875 Bytes. Nothing untoward in the server logs basically. Pull to the same server works fine too. I can attach log messages if helpful.

KevinJump commented 1 year ago

Hi,

We have seen something similar before - (where everything works up until the upload) . and it was a firewall proxy thing,

every request up until that point is local to the source server or a get request to the remote one. the upload is the first POST request sent from the source to the target. and i think from memory. last time we saw this the post requests where being rejected by the client's firewall. (its a multi-part form post, containing a zip file if that helps).

Kevin

BarryFogarty commented 1 year ago

Hi Kevin, thanks for the prompt reply - to be clear the Uploaded file is saved to App_Data/Temp/usync/receive/{GUID}/.. and the structure/contents look correct. It just seems to be whatever happens after that causing the problem. Server logs give no further clues however.

BarryFogarty commented 1 year ago

Any other suggestions on how to debug this error @KevinJump? The POST request successfully uploads the file to the target server, but the response still contains an error and the pushed update is not processed (i.e. synced to the target DB).

Are there any other basic checks to try where pull works but not push (user permissions etc)?

KevinJump commented 1 year ago

Hi

It might be worth checking that both sites have a similar usync8.config file, with uSync.Complete on v8 there needs to be a publisher set in the config file at both ends or sometimes things can get pushed but then there isn't something at the other end to import it.

we have reference configs here : https://github.com/Jumoo/uSync.Complete.Issues/tree/main/configs

they don't need to be exactly like this but, you could use these to spot any issues.

also it probably would make sense to turn debugging on on the target site. (https://docs.jumoo.co.uk/usync/8.x/uSync/guides/debugging) if things are going wrong on the target this might shed some light when it happens.

Kevin

BarryFogarty commented 1 year ago

Hi Kevin,

Thasnks for the info, I have compared the configs which are pretty standard, and I have ensure the server name is being changed for each environment. I still get the error on push, but now a warning is logged on the source (pushing) server after the POST request is made:

Upload didn't return the expected Guid "<guid xmlns=\"http://schemas.microsoft.com/2003/10/Serialization/\">d0521382-87ba-4bd2-be54-a770d4f026f0</guid>"

Does this ring any bells? As before, I can succesfully pull content from a target, but pushing fails with the above warning logged on the server attempting to push. The returned Guid does not match with anything I can find related to the upload on the server, but if you know what it should match to please let me know so I can check it.

EDIT: It looks like the Guid matches the uploaded folder name, but it seems to get deleted (by the clean operation) before I can confirm.

KevinJump commented 1 year ago

Oh, i wonder if there is load balancing anywhere ? the GUID id values are only generated once at the start of the process - but if you hit two servers in the process each one would then create its own guid - so this might be the error (i am sort of guessing but based on how it works that could be a place to check).

BarryFogarty commented 1 year ago

There is no LB anywhere between the QA and UAT site instances I am currently testing. Both are Windows boxes running IIS without any URL proxying etc. The Guid that the source (pushing) server is receiving back from the upload matches the folder name created on the target machine - i.e. App_Data/Temp/usync/receive/{GUID}, but I still get a warning logged to say it is unexpected as per my previous post (There are no actual errors logged, on either the source or the target). On the target there are normal looking debug log messages regarding receving the pushpack and unpacking it. The content of the received folder look fine. Basically everything seems to be working, but if I inspect the API calls on the source, the 4th 'PerformAction' call ("Push" step), says it was successful, but has an empty object in the actions param of the response (see below). The 5th and final 'PerformAction' call (also "Push" step), reports the error with the response as per the original post in the thread. Not sure what else I can try other than completely reinstalling it / trying on another site, so any other pointers before I go to that stage would be great.

4th 'PerformAction' POST response (last one before the error report):

{
  "id": "f6046bee-29aa-4af4-ad4d-e4337857a1e4",
  "processComplete": false,
  "success": true,
  "message": null,
  "error": null,
  "actions": [],
  "actionComplete": false,
  "nextAction": "export",
  "nextFolder": null,
  "stepIndex": 4,
  "nextPage": 0,
  "items": [
    {
      "name": "New uSync Page to Push",
      "udi": "umb://document/b5483ed5cdce4d54b997ac7ada91baaf",
      "flags": "IncludeMediaFiles",
      "change": "NoChange"
    }
  ],
  "progress": {
    "currentStepName": "Push",
    "currentStepIndex": 4,
    "steps": [
      {
        "index": 0,
        "name": "Calculate",
        "icon": "icon-settings usync-cogs",
        "status": "Complete"
      },
      {
        "index": 2,
        "name": "Export",
        "icon": "icon-box usync-jump",
        "status": "Complete"
      },
      {
        "index": 4,
        "name": "Push",
        "icon": "icon-shipping usync-truck",
        "status": "InProgress"
      },
      {
        "index": 5,
        "name": "Report",
        "icon": "icon-slideshow",
        "status": "Pending"
      }
    ]
  }
}
stevetemple commented 1 year ago

Hi Kevin,

I've made some progress with this:

In our codebase there is some modification to the WebApi Serialization:

 public static class WebApiConfig
    {
        public static void Register(HttpConfiguration config)
        {
            var formatters = GlobalConfiguration.Configuration.Formatters;
            var jsonFormatter = formatters.JsonFormatter;
            var settings = jsonFormatter.SerializerSettings;

            var enumConverter = new Newtonsoft.Json.Converters.StringEnumConverter();
            jsonFormatter.SerializerSettings.Converters.Add(enumConverter);

            settings.Formatting = Formatting.Indented;
            settings.ContractResolver = new CamelCasePropertyNamesContractResolver();

            config.MapHttpAttributeRoutes();

            config.Formatters.XmlFormatter.SupportedMediaTypes.Add(new System.Net.Http.Headers.MediaTypeHeaderValue("multipart/form-data"));
        }
    }

Removing this, breaks some other bits, but fixes uSync issues :)

stevetemple commented 1 year ago

Specifically this line: config.Formatters.XmlFormatter.SupportedMediaTypes.Add(new [System.Net](http://system.net/).Http.Headers.MediaTypeHeaderValue("multipart/form-data"));

I guess XML is getting used for the data uSync is posting

KevinJump commented 1 year ago

Hi,

yeah that makes sense, we actually set things like that (but not the xml formatter stuff in a TypeFilterAttribute.

 public class PublisherJsonFormatterAttribute : TypeFilterAttribute
    {
        public PublisherJsonFormatterAttribute() : base(typeof(PublisherJsonFormatterFilter))
        {
            Order = 2;
        }
    }

with a format filter which sets the json formatting stuff onExecuting. it means we can apply a attribute to a controller to ensure it always uses the same formatter.

e.g

    [PublisherJsonFormatter]
    public partial class uSyncReceiveApiController : UmbracoApiController
    {

obviously we are not setting everything this way, looks like some of your defaults are coming through. not sure if we are able to stop that (we might in speicifc cases when we know them but not cater for everything..) will take a look.

BarryFogarty commented 1 year ago

Thanks Kevin - we have a workaround that allows removing the formatter change from the default WebAPI config.

stevetemple commented 1 year ago

Thanks for your time Kevin!