Connection forcibly closed by remote host

Support
#1

getting this strange error;

----------------------------------------# error: [Errno 10054] An existing connection was forcibly closed by the remote host
#     self._sock.sendall(view[write_offset:write_offset+buffer_size])
#   File "C:\Program Files\Autodesk\Maya2015\bin\python27.zip\socket.py", line 303, in flush
#     self.wfile.flush()
#   File "C:\Program Files\Autodesk\Maya2015\bin\python27.zip\SocketServer.py", line 693, in finish
#     self.finish()
#   File "C:\Program Files\Autodesk\Maya2015\bin\python27.zip\SocketServer.py", line 640, in __init__
#     self.RequestHandlerClass(request, client_address, self)
#   File "C:\Program Files\Autodesk\Maya2015\bin\python27.zip\SocketServer.py", line 323, in finish_request
#     self.finish_request(request, client_address)
#   File "C:\Program Files\Autodesk\Maya2015\bin\python27.zip\SocketServer.py", line 582, in process_request_thread
# Traceback (most recent call last):

('127.0.0.1', 51853) Exception happened during processing of request from
----------------------------------------// FTrackCore.api.event.hub.EventHub : Sent packet: 2::: // 
// FTrackCore.api.event.hub.EventHub : Received packet: 2:: //

The strange thing is that it comes when I have imported a certain amount of ftrack assets into the scene. Its during the Ftrack validation. The number of assets seems to be around 7-8 where pyblish- ui starts crashing.
I think it might be something to do with with Ftrack sending these “heart beats”, which interferes with pyblish

#2

Hm, it doesn’t look related to Pyblish.

I suspect you might be seeing the same error if you run the body of a plug-in by hand 7-8 times.

If I had to guess, I’d say it looks like your plug-in(s) is opening a new connection to FTrack each time, and eventually FTrack says “no, no more”. Is there a “shutdown” or “close” on the FTrack connection perhaps? You may have to do some cleanup.

It’s possibly related, but what makes you think that?

#3

The thing is that its only processing one instance; a scene instance. Does Pyblish somehow freeze the socket communication with Maya?

I’ll query ftrack about what the “heart beats” exactly are.

#4

Hm, no Pyblish isn’t freezing anything. To the best of my knowledge, sockets operate on a per-port basis, and a port can only handle a single request at a time. But since FTrack and Pyblish operate on different ports (Pyblish using 9090, along with 6001+ per host) they shouldn’t be able to interact or interfere with each other.

The only freezing going on would be when Maya is processing any command including it’s own api, like maya.cmds. Maya can only handle a single request as well and will freeze until a command is finished. But this should again not interfere with FTrack since it is most likely operating on a separate thread, like Pyblish, and isn’t using the Maya API except when it is obvious that it does so. Heartbeats is an example of when Maya interaction would not be required.

#5

This is from a conversation with @martin;

Hey,

Those packets are from the event hub in the ftrack API communicating with the server.

The packets you show (2) refer to a ‘heartbeat’ event – the client and server check in every few seconds to check that the connection is still up.

The error itself is caused by the ftrack server disconnecting the event hub remotely. This usually only happens when the server thinks your event hub is no longer there (ie. no heartbeats received for a while).

It could be something starving the background processing thread from replying to the server quickly enough. Are you able to create a reproducible test case (outside of pyblish code ideally)?

As I’m not very hot with threading, could @marcus help me setup a test that outside of Pyblish?

#6

Sure, could you give me the code you use to initiate a connection to ftrack?

#7

This is the ftrack validator, that crashes Pyblish;

import pyblish.api
import ftrack


@pyblish.api.log
class ValidateFtrack(pyblish.api.Validator):

    """ Validate the existence of Asset, AssetVersion and Components.
    """

    order = pyblish.api.Validator.order + 0.1
    optional = True
    label = 'Ftrack'

    def process(self, instance, context):

        # skipping instance if ftrackData isn't present
        if not context.has_data('ftrackData'):
            self.log.info('No ftrackData present. Skipping this instance')
            return

        # skipping instance if ftrackComponents isn't present
        if not instance.has_data('ftrackComponents'):
            self.log.info('No ftrackComponents present\
                           Skipping this instance')
            return

        ftrack_data = context.data('ftrackData').copy()
        task = ftrack.Task(ftrack_data['Task']['id'])

        # checking asset
        create_asset = True
        asset = None
        if instance.has_data('ftrackAssetType'):
            asset_type = instance.data('ftrackAssetType')
        else:
            asset_type = ftrack_data['Task']['code']

        assets = task.getAssets(assetTypes=[asset_type])

        if len(assets) == 0:
            instance.set_data('ftrackAssetCreate', value=True)
            return

        if instance.has_data('ftrackAssetName'):

            # searching for existing asset
            asset_name = instance.data('ftrackAssetName')
            for a in assets:
                if asset_name.lower() == a.getName().lower():
                    asset = a
                    create_asset = False

                    msg = 'Found existing asset from ftrackAssetName'
                    self.log.info(msg)
        else:
            # if only one asset exists, then we'll use that asset
            msg = "Can't compute asset."
            if len(assets) == 1:
                print('FOUND ONE ASSET')
                for a in assets:
                    print a
                    asset = a
                    create_asset = False
                assert asset, msg
                self.log.info('Found existing asset by default.')
            elif len(assets) > 1:
                asset_name = ftrack_data['Task']['type']
                for a in assets:
                    msg += " Multiple assets on shot: \n\n%s" % a
                    if asset_name.lower() == a.getName().lower():
                        asset = a
                    create_asset = False
                assert asset, msg
                self.log.info('Found existing asset by default.')
            else:
                self.log.info('No asset found, new one will be created.')

        # adding asset to ftrack data
        if asset:
            asset_data = {'id': asset.getId(),
                          'name': asset.getName()}
            instance.set_data('ftrackAsset', value=asset_data)

        instance.set_data('ftrackAssetCreate', value=create_asset)

        # if we are creating a new asset,
        # then we don't need to validate the rest
        if create_asset:
            return

        # checking version
        msg = 'Missing version in context.'
        assert context.has_data('version'), msg

        version_number = int(context.data('version'))
        create_version = True
        version = None

        # search for existing version
        for v in asset.getVersions():
            if int(v.getVersion()) == version_number:

                msg = "AssetVersion exists but is not visible in UI."
                assert v.get('ispublished'), msg

                version = v
                # ftrack_data['AssetVersion'] = {'id': v.getId(),
                #                                'number': version_number}
                asset_version = {'id': v.getId(), 'number': version_number}
                instance.set_data('ftrackAssetVersion', value=asset_version)

                create_version = False

                msg = 'Found existing version number: %s' % version_number
                self.log.info(msg)

        instance.set_data('ftrackAssetVersionCreate', value=create_version)

        # if we are creating a new asset version,
        # then we don't need to validate the rest
        if create_version:
            return

        # checking components
        online_components = version.getComponents()
        ftrack_components = instance.data('ftrackComponents').copy()

        for local_c in ftrack_components:
            for online_c in online_components:
                if local_c == online_c.getName():

                    # warning about existing components
                    msg = 'Component "%s" already exists. ' % local_c
                    msg += 'To replace it delete it in the browser first.'
                    self.log.warning(msg)

                    # validating review components
                    if 'reviewable' in ftrack_components[local_c]:
                        msg = 'Reviewable component already exists in the\
                               version. To replace it\
                               delete it in the webUI first'
                        assert online_c.getName() not in (
                            'ftrackreview-mp4', 'ftrackreview-webm'), msg

The connection comes from the ftrack api; http://ftrack.rtd.ftrack.com/en/latest/developing/getting_started.html, where the first connection in the validator is task = ftrack.Task(ftrack_data['Task']['id'])

#8

Ok, is it also the only connection, or are there more being made?

#9

Did you say it crashes Pyblish? How do you mean?

#10

It closes pyblish ui with the error posted.

#11

That is odd, we could try and use the demo account to ftrack to reproduce it fully. Did you get a login? I sent you an invite some time ago.

#12

I think I have narrowed the search down to an extractor, that is saving the scene. The saving is taking an oddly long time for the size of the scene (~8mb), which is freezing Maya.

#13

Still sounds very curious. Do keep posting updates as you find them.

You could also try this.

for x in range(10):
  print ftrack.Task(ftrack_data['Task']['id'])

It should print the task 10 times, but it’s possible that after 7-8 it chokes. Which could indicate that the connection isn’t closed automatically and that you might have to cleanup by hand somehow.

E.g.

for x in range(10):
  task = ftrack.Task(ftrack_data['Task']['id'])
  print task
  task.close_connection()
#14

I disabled the scene saving extractor, and added this to the ftrack validator;

        for x in range(10):
            self.log.info(ftrack.Task(ftrack_data['Task']['id']))

Which worked fine, and published successfully, so its definitely the scene saving extractor. Don’t get why this would happen, but I think I might work around the problem by having a scene-saved-validator instead of an extractor.

#15

Ah, I think it may add to the confusion that the GUI currently is showing you the wrong current plug-in being processed. It’s showing you the previous item as the current item. Is that why you though it was the Validator at first? It’s a known bug that I haven’t found a clean solution for yet…

Could you post the extractor?

#16

Yeah:)

Could you post the extractor?

import maya
import pyblish.api


@pyblish.api.log
class ExtractSceneSave(pyblish.api.Extractor):
    """
    """

    order = pyblish.api.Extractor.order
    families = ['scene']
    label = 'Scene Save'

    def process(self, instance):

        maya.cmds.file(s=True)
#17

Sorry about that, I know it’s confusing…

What, is that the extractor causing the issue? :open_mouth: I don’t understand how it can cause any harm.

Shot in the dark, but sometimes sockets take a moment to close. You could try adding time.sleep(5) just before you save the file, it will give sockets some time to close and might tell us whether that’s the case or not.

#18

One more thing, it’s possible that the ftrack API is trying to automatically close a connection during garbage collection.

If that’s the case, then it could be that as soon as the plug-in is finished, Python will go ahead and garbage collect all variables within it. It could be the case that ftrack listens for that, and tries to close the connection. If that is the case, then that would explain why your innocent-looking extractor is getting the blame for an error cause by a post-garbage collection trigger.

If you can dig up the Task class in the API, look for a __del__ method on it. That would be where something like this could happen.

#19

Can’t find any __del__ method on the task or its parent class, only a delete method on its parent class;

    def delete(self):
        data = {'entityType':self._type,'entityId':self.getId(),'type':'delete'}
        response = self.xmlServer.action('set',data)

        return response
#20

Ok, then that’s probably not the case.

If you can find a way to reproduce it with your series of plug-ins, but using the demo account, I could maybe have a closer look.