[NXDRIVE-831] Fix test_dedup_folders on Windows: error: can't start new thread - Nuxeo Issue Tracker

XML

Word

Printable

Details

Type: Bug
Status: Resolved
Priority: Minor
Resolution: Won't Fix
Affects Version/s: None
Fix Version/s: 2.5.5
Component/s: Tests

Epic Link:
Random bug
Tags:
- nxMS

Description

See https://qa.nuxeo.org/jenkins/view/Drive/job/Drive/job/FT-drive/job/master/65/consoleFull

20:10:50 [WINSLAVE] [INFO]      [exec] nuxeo-drive-client\tests\test_synchronization_dedup.py ..F
20:10:50 [WINSLAVE] [INFO]      [exec] =========================== short test summary info ===========================
20:10:50 [WINSLAVE] [INFO]      [exec] FAIL nuxeo-drive-client/tests/test_synchronization_dedup.py::TestDedupInsensitiveCaseSync::test_dedup_folders
20:10:50 [WINSLAVE] [INFO]      [exec] ================================== FAILURES ===================================
20:10:50 [WINSLAVE] [INFO]      [exec] _______________ TestDedupInsensitiveCaseSync.test_dedup_folders _______________
20:10:50 [WINSLAVE] [INFO]      [exec] self = <tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync testMethod=test_dedup_folders>
20:10:50 [WINSLAVE] [INFO]      [exec] result = <TestCaseFunction 'test_dedup_folders'>
20:10:50 [WINSLAVE] [INFO]      [exec]     def run(self, result=None):
20:10:50 [WINSLAVE] [INFO]      [exec]         orig_result = result
20:10:50 [WINSLAVE] [INFO]      [exec]         if result is None:
20:10:50 [WINSLAVE] [INFO]      [exec]             result = self.defaultTestResult()
20:10:50 [WINSLAVE] [INFO]      [exec]             startTestRun = getattr(result, 'startTestRun', None)
20:10:50 [WINSLAVE] [INFO]      [exec]             if startTestRun is not None:
20:10:50 [WINSLAVE] [INFO]      [exec]                 startTestRun()
20:10:50 [WINSLAVE] [INFO]      [exec]         self._resultForDoCleanups = result
20:10:50 [WINSLAVE] [INFO]      [exec]         result.startTest(self)
20:10:50 [WINSLAVE] [INFO]      [exec]         testMethod = getattr(self, self._testMethodName)
20:10:50 [WINSLAVE] [INFO]      [exec]         if (getattr(self.__class__, "__unittest_skip__", False) or
20:10:50 [WINSLAVE] [INFO]      [exec]             getattr(testMethod, "__unittest_skip__", False)):
20:10:50 [WINSLAVE] [INFO]      [exec]             # If the class or method was skipped.
20:10:50 [WINSLAVE] [INFO]      [exec]             try:
20:10:50 [WINSLAVE] [INFO]      [exec]                 skip_why = (getattr(self.__class__, '__unittest_skip_why__', '')
20:10:50 [WINSLAVE] [INFO]      [exec]                             or getattr(testMethod, '__unittest_skip_why__', ''))
20:10:50 [WINSLAVE] [INFO]      [exec]                 self._addSkip(result, skip_why)
20:10:50 [WINSLAVE] [INFO]      [exec]             finally:
20:10:50 [WINSLAVE] [INFO]      [exec]                 result.stopTest(self)
20:10:50 [WINSLAVE] [INFO]      [exec]             return
20:10:50 [WINSLAVE] [INFO]      [exec]         try:
20:10:50 [WINSLAVE] [INFO]      [exec]             success = False
20:10:50 [WINSLAVE] [INFO]      [exec]             try:
20:10:50 [WINSLAVE] [INFO]      [exec]                 self.setUp()
20:10:50 [WINSLAVE] [INFO]      [exec]             except SkipTest as e:
20:10:50 [WINSLAVE] [INFO]      [exec]                 self._addSkip(result, str(e))
20:10:50 [WINSLAVE] [INFO]      [exec]             except KeyboardInterrupt:
20:10:50 [WINSLAVE] [INFO]      [exec]                 raise
20:10:50 [WINSLAVE] [INFO]      [exec]             except:
20:10:50 [WINSLAVE] [INFO]      [exec]                 result.addError(self, sys.exc_info())
20:10:50 [WINSLAVE] [INFO]      [exec]             else:
20:10:50 [WINSLAVE] [INFO]      [exec]                 try:
20:10:50 [WINSLAVE] [INFO]      [exec] >                   testMethod()
20:10:50 [WINSLAVE] [INFO]      [exec] cleanUpSuccess = True
20:10:50 [WINSLAVE] [INFO]      [exec] orig_result = <TestCaseFunction 'test_dedup_folders'>
20:10:50 [WINSLAVE] [INFO]      [exec] result     = <TestCaseFunction 'test_dedup_folders'>
20:10:50 [WINSLAVE] [INFO]      [exec] self       = <tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync testMethod=test_dedup_folders>
20:10:50 [WINSLAVE] [INFO]      [exec] success    = False
20:10:50 [WINSLAVE] [INFO]      [exec] testMethod = <bound method TestDedupInsensitiveCaseSync.test_dedup_folders of <tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync testMethod=test_dedup_folders>>
20:10:50 [WINSLAVE] [INFO]      [exec] ..\deploy-dir\drive-2.7.13-python\lib\unittest\case.py:329: 
20:10:50 [WINSLAVE] [INFO]      [exec] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
20:10:50 [WINSLAVE] [INFO]      [exec] self = <tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync testMethod=test_dedup_folders>
20:10:50 [WINSLAVE] [INFO]      [exec]     def test_dedup_folders(self):
20:10:50 [WINSLAVE] [INFO]      [exec]         local = self.local_client_1
20:10:50 [WINSLAVE] [INFO]      [exec]         remote = self.remote_document_client_1
20:10:50 [WINSLAVE] [INFO]      [exec]         # Create documents in the remote root workspace
20:10:50 [WINSLAVE] [INFO]      [exec]         # then synchronize
20:10:50 [WINSLAVE] [INFO]      [exec]         test_uid = remote.make_folder('/', 'test')
20:10:50 [WINSLAVE] [INFO]      [exec]         Test_uid = remote.make_folder('/', 'Test')
20:10:50 [WINSLAVE] [INFO]      [exec]         remote.make_file('/test', 'test.txt', 'plop')
20:10:50 [WINSLAVE] [INFO]      [exec]         remote.make_file('/Test', 'test_2.txt', 'plop')
20:10:50 [WINSLAVE] [INFO]      [exec]         self.wait_sync(wait_for_async=True)
20:10:50 [WINSLAVE] [INFO]      [exec] >       childs = local.get_children_info('/')
20:10:50 [WINSLAVE] [INFO]      [exec] Test_uid   = 'f4a198e0-83c1-4887-b977-49e5a8e04834'
20:10:50 [WINSLAVE] [INFO]      [exec] local      = <tests.win_local_client.WindowsLocalClient object at 0x7F435210>
20:10:50 [WINSLAVE] [INFO]      [exec] remote     = <RemoteDocumentClient base_folder=None, blob_timeout=60, check_suspended=None,...3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpfmnmgm-nxdrive-uploads', user_id='driveuser_1'>
20:10:50 [WINSLAVE] [INFO]      [exec] self       = <tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync testMethod=test_dedup_folders>
20:10:50 [WINSLAVE] [INFO]      [exec] test_uid   = '1e9d81b4-cd3c-46f1-8abb-b772ebe5e719'
20:10:50 [WINSLAVE] [INFO]      [exec] nuxeo-drive-client\tests\test_synchronization_dedup.py:135: 
20:10:50 [WINSLAVE] [INFO]      [exec] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
20:10:50 [WINSLAVE] [INFO]      [exec] self = <tests.win_local_client.WindowsLocalClient object at 0x7F435210>
20:10:50 [WINSLAVE] [INFO]      [exec] ref = '/'
20:10:50 [WINSLAVE] [INFO]      [exec]     def get_children_info(self, ref):
20:10:50 [WINSLAVE] [INFO]      [exec]         os_path = self.abspath(ref)
20:10:50 [WINSLAVE] [INFO]      [exec]         result = []
20:10:50 [WINSLAVE] [INFO]      [exec] >       children = os.listdir(os_path)
20:10:50 [WINSLAVE] [INFO]      [exec] E       WindowsError: [Error 3] The system cannot find the path specified: u'C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpxvzuhadrive-1\\Nuxeo Drive\\Nuxeo Drive Test Workspace\\*.*'
20:10:50 [WINSLAVE] [INFO]      [exec] os_path    = 'C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\Nuxeo Drive\Nuxeo Drive Test Workspace'
20:10:50 [WINSLAVE] [INFO]      [exec] ref        = '/'
20:10:50 [WINSLAVE] [INFO]      [exec] result     = []
20:10:50 [WINSLAVE] [INFO]      [exec] self       = <tests.win_local_client.WindowsLocalClient object at 0x7F435210>
20:10:50 [WINSLAVE] [INFO]      [exec] nuxeo-drive-client\nxdrive\client\local_client.py:521: WindowsError
20:10:50 [WINSLAVE] [INFO]      [exec] ---------------------------- Captured stderr call -----------------------------
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,594 3908 3176 INFO     nxdrive.manager    --consider-ssl-errors option is True, will verify HTTPS certificates
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,595 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create DAO on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\nuxeo-drive-conf\manager.db
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,595 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create main connexion on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\nuxeo-drive-conf\manager.db (dir exists: 1 / file exists: 0)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,611 3908 3176 TRACE    nxdrive.manager    Manager.refresh_proxies(proxy_settings=None, device_config=None)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,614 3908 3176 TRACE    nxdrive.manager    Setting self.proxies['default'] = None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,615 3908 3176 DEBUG    nxdrive.osi        Using Windows OS integration
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,621 3908 3176 DEBUG    nxdrive.updater    Application is not frozen, cannot build Esky instance, as a consequence update features won't be available
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,624 3908 3176 INFO     nxdrive.manager    --consider-ssl-errors option is True, will verify HTTPS certificates
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,625 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create DAO on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpawqdyidrive-2\nuxeo-drive-conf\manager.db
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,625 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create main connexion on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpawqdyidrive-2\nuxeo-drive-conf\manager.db (dir exists: 1 / file exists: 0)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,640 3908 3176 TRACE    nxdrive.manager    Manager.refresh_proxies(proxy_settings=None, device_config=None)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,641 3908 3176 TRACE    nxdrive.manager    Setting self.proxies['default'] = None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,641 3908 3176 DEBUG    nxdrive.osi        Using Windows OS integration
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,647 3908 3176 DEBUG    nxdrive.updater    Application is not frozen, cannot build Esky instance, as a consequence update features won't be available
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,650 3908 3176 DEBUG    tests.common_unit_test Will use http://localhost:8080/nuxeo#NXDRIVE as url
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,655 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,655 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-administrator-device', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,698 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,709 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"11430878-e9f7-42df-b954-df2ad996b760","path":"/","type":"Root","state":null,"parentRef":"/","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":null,"title":"11430878-e9f7-42df-b954-df2ad996b760","properties":{"common:icon-expanded":null,"common:icon":null,"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":null,"dc:modified":null,"dc:lastContributor":null,"dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":null,"dc:title":null,"dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":[],"dc:source":null,"dc:publisher":null},"facets":["Folderish","NotCollectionMember"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,710 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"userNames": "user_1, user_2", "permission": "ReadWrite"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,812 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests' with cookies [] has content-type 'text/plain;charset=UTF-8'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,813 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,822 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"ae86ff96-cc87-4964-90c1-b11d9c39c6b9","path":"/default-domain/workspaces","type":"WorkspaceRoot","state":"project","parentRef":"5f2d2b29-5438-4fa9-874b-8e863811b154","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492627230228","title":"Workspaces","lastModified":"2017-04-19T18:40:30.228Z","properties":{"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"system","dc:modified":"2017-04-19T18:40:30.228Z","dc:lastContributor":"system","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T18:40:30.228Z","dc:title":"Workspaces","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["system"],"dc:source":null,"dc:publisher":null},"facets":["Folderish","SuperSpace","HiddenInCreation","NotCollectionMember"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,822 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.GetChildren with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"input": "doc:ae86ff96-cc87-4964-90c1-b11d9c39c6b9", "params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,832 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.GetChildren' with cookies []: '{"entity-type":"documents","entries":[{"entity-type":"document","repository":"default","uid":"5deda0ba-f010-4eb6-bb00-1387d58116fa","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"ae86ff96-cc87-4964-90c1-b11d9c39c6b9","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632554737","title":"Nuxeo Drive Test Workspace","lastModified":"2017-04-19T20:09:14.737Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:themePage":"workspace","webc:logo":null,"webc:name":null,"webc:email":null,"webc:welcomeMedia":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:content":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2017-04-19T20:09:14.737Z","dc:lastContributor":"Administrator","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:14.737Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"]}]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,834 3908 3176 DEBUG    tests.common_unit_test SuperWorkspace info: {u'changeToken': u'1492627230228', u'uid': u'ae86ff96-cc87-4964-90c1-b11d9c39c6b9', u'repository': u'default', u'title': u'Workspaces', u'lastModified': u'2017-04-19T18:40:30.228Z', u'facets': [u'Folderish', u'SuperSpace', u'HiddenInCreation', u'NotCollectionMember'], u'entity-type': u'document', u'state': u'project', u'isCheckedOut': True, u'parentRef': u'5f2d2b29-5438-4fa9-874b-8e863811b154', u'path': u'/default-domain/workspaces', u'isProxy': False, u'type': u'WorkspaceRoot', u'properties': {u'dc:subjects': [], u'dc:source': None, u'common:icon-expanded': None, u'dc:valid': None, u'dc:language': None, u'dc:creator': u'system', u'dc:title': u'Workspaces', u'dc:expired': None, u'dc:coverage': None, u'dc:modified': u'2017-04-19T18:40:30.228Z', u'dc:lastContributor': u'system', u'dc:created': u'2017-04-19T18:40:30.228Z', u'dc:contributors': [u'system'], u'common:icon': u'/icons/workspace.gif', u'dc:issued': None, u'dc:publisher': None, u'dc:nature': None, u'dc:format': None, u'dc:description': None, u'dc:rights': None}, u'isVersion': False}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,834 3908 3176 DEBUG    tests.common_unit_test SuperWorkspace children: {u'entity-type': u'documents', u'entries': [{u'changeToken': u'1492632554737', u'uid': u'5deda0ba-f010-4eb6-bb00-1387d58116fa', u'repository': u'default', u'title': u'Nuxeo Drive Test Workspace', u'lastModified': u'2017-04-19T20:09:14.737Z', u'facets': [u'Folderish', u'SuperSpace'], u'entity-type': u'document', u'state': u'project', u'isCheckedOut': True, u'parentRef': u'ae86ff96-cc87-4964-90c1-b11d9c39c6b9', u'path': u'/default-domain/workspaces/nuxeo-drive-test-workspace', u'isProxy': False, u'type': u'Workspace', u'properties': {u'webc:url': None, u'dc:language': None, u'dc:valid': None, u'dc:subjects': [], u'webc:theme': u'sites', u'dc:title': u'Nuxeo Drive Test Workspace', u'dc:coverage': None, u'dc:lastContributor': u'Administrator', u'dc:created': u'2017-04-19T20:09:14.737Z', u'webc:email': None, u'dc:contributors': [u'Administrator'], u'dc:publisher': None, u'dc:format': None, u'webc:baseline': None, u'dc:source': None, u'common:icon-expanded': None, u'webc:useCaptcha': None, u'dc:nature': None, u'dc:creator': u'Administrator', u'webc:logo': None, u'webc:name': None, u'file:content': None, u'webc:welcomeText': None, u'dc:description': None, u'dc:rights': None, u'webc:welcomeMedia': None, u'webc:isWebContainer': None, u'webc:template': None, u'common:icon': u'/icons/workspace.gif', u'dc:expired': None, u'webc:moderationType': u'aposteriori', u'webc:themePage': u'workspace', u'dc:modified': u'2017-04-19T20:09:14.737Z', u'webc:themePerspective': None, u'dc:issued': None, u'files:files': [], u'publish:sections': []}, u'isVersion': False}]}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,835 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,844 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"5deda0ba-f010-4eb6-bb00-1387d58116fa","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"ae86ff96-cc87-4964-90c1-b11d9c39c6b9","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632554737","title":"Nuxeo Drive Test Workspace","lastModified":"2017-04-19T20:09:14.737Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:themePage":"workspace","webc:logo":null,"webc:name":null,"webc:email":null,"webc:welcomeMedia":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:content":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2017-04-19T20:09:14.737Z","dc:lastContributor":"Administrator","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:14.737Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,844 3908 3176 DEBUG    tests.common_unit_test Workspace info: {u'changeToken': u'1492632554737', u'uid': u'5deda0ba-f010-4eb6-bb00-1387d58116fa', u'repository': u'default', u'title': u'Nuxeo Drive Test Workspace', u'lastModified': u'2017-04-19T20:09:14.737Z', u'facets': [u'Folderish', u'SuperSpace'], u'entity-type': u'document', u'state': u'project', u'isCheckedOut': True, u'parentRef': u'ae86ff96-cc87-4964-90c1-b11d9c39c6b9', u'path': u'/default-domain/workspaces/nuxeo-drive-test-workspace', u'isProxy': False, u'type': u'Workspace', u'properties': {u'webc:url': None, u'dc:language': None, u'dc:valid': None, u'dc:subjects': [], u'webc:theme': u'sites', u'dc:title': u'Nuxeo Drive Test Workspace', u'dc:coverage': None, u'dc:lastContributor': u'Administrator', u'dc:created': u'2017-04-19T20:09:14.737Z', u'webc:email': None, u'dc:contributors': [u'Administrator'], u'dc:publisher': None, u'dc:format': None, u'webc:baseline': None, u'dc:source': None, u'common:icon-expanded': None, u'webc:useCaptcha': None, u'dc:nature': None, u'dc:creator': u'Administrator', u'webc:logo': None, u'webc:name': None, u'file:content': None, u'webc:welcomeText': None, u'dc:description': None, u'dc:rights': None, u'webc:welcomeMedia': None, u'webc:isWebContainer': None, u'webc:template': None, u'common:icon': u'/icons/workspace.gif', u'dc:expired': None, u'webc:moderationType': u'aposteriori', u'webc:themePage': u'workspace', u'dc:modified': u'2017-04-19T20:09:14.737Z', u'webc:themePerspective': None, u'dc:issued': None, u'files:files': [], u'publish:sections': []}, u'isVersion': False}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,851 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create DAO on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\nuxeo-drive-conf\ndrive_0f9fb600253c11e7a979080027181249.db
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,851 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create main connexion on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\nuxeo-drive-conf\ndrive_0f9fb600253c11e7a979080027181249.db (dir exists: 1 / file exists: 0)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,865 3908 3176 TRACE    nxdrive.engine.dao.sqlite Vacuum sqlite
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,871 3908 3176 TRACE    nxdrive.engine.dao.sqlite Vacuum sqlite finished
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,877 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,878 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,914 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Windows+Desktop&revoke=false&deviceId=0f7cc4b0253c11e7a341080027181249&permission=ReadWrite with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,924 3908 3176 TRACE    nxdrive.client.base_automation_client Got token '344987ac-b96d-4116-a4c8-7d79785def17' with cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,937 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': '344987ac-b96d-4116-a4c8-7d79785def17', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'}, cookies [] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,948 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo' with cookies []: '{"serverVersion":"9.2-SNAPSHOT","updateSiteURL":"http://community.nuxeo.com/static/drive/","betaUpdateSiteURL":"http://community.nuxeo.com/static/drive-tests/"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,950 3908 3176 DEBUG    nxdrive.engine.engine Fetched update info for engine [localhost] from server http://localhost:8080/nuxeo/: {u'serverVersion': u'9.2-SNAPSHOT', u'updateSiteURL': u'http://community.nuxeo.com/static/drive/', u'betaUpdateSiteURL': u'http://community.nuxeo.com/static/drive-tests/'}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,963 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,963 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': '344987ac-b96d-4116-a4c8-7d79785def17', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:14,996 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': '344987ac-b96d-4116-a4c8-7d79785def17', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'}, cookies [Cookie(version=0, name='X-Authentication-Token', value='344987ac-b96d-4116-a4c8-7d79785def17', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,003 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies [Cookie(version=0, name='X-Authentication-Token', value='344987ac-b96d-4116-a4c8-7d79785def17', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]: '{"canScrollDescendants":false,"canCreateChild":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","lockInfo":null,"creationDate":1,"creator":"system","folder":true,"parentId":null,"canRename":false,"canDelete":false,"lastContributor":"system","lastModificationDate":1,"userName":"driveuser_1"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,005 3908 3176 TRACE    nxdrive.engine.dao.sqlite Will not push pair: locally_created, pair=None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,007 3908 3176 TRACE    nxdrive.engine.dao.sqlite Updating remote state for row = StateRow[1](Local: u'/', Remote: None, Local state: created, Remote state: unknown, State: locally_created) with info = RemoteFileInfo(name=u'Nuxeo Drive', uid=u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#', parent_uid=None, path=u'/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#', folderish=True, last_modification_time=datetime.datetime(1970, 1, 1, 1, 0), last_contributor=u'system', digest=None, digest_algorithm=None, download_url=None, can_rename=False, can_delete=False, can_update=False, can_create_child=False, lock_owner=None, lock_created=None, can_scroll_descendants=False) (force: False)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,010 3908 3176 TRACE    nxdrive.engine.dao.sqlite Will not push pair: locally_created, pair=None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,012 3908 3176 TRACE    nxdrive.client.local_client Setting xattr ndriveroot with value 'http://localhost:8080/nuxeo/|driveuser_1|0f7cc4b0253c11e7a341080027181249|0f9fb600253c11e7a979080027181249' on u'\\\\?\\C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpxvzuhadrive-1\\Nuxeo Drive'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,013 3908 3176 TRACE    nxdrive.client.local_client Setting xattr ndrive with value 'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#' on u'\\\\?\\C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpxvzuhadrive-1\\Nuxeo Drive'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,013 3908 3176 TRACE    nxdrive.engine.dao.sqlite Try to synchronize state for [local_path=/, remote_name=None, version=0] with version=0
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,016 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Queuing 0 children of 'StateRow[1](Local: u'/', Remote: None, Local state: created, Remote state: unknown, State: locally_created)'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,029 3908 3176 DEBUG    nxdrive.engine.watcher.local_watcher Windows detected so delete event will be delayed by 2000ms
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,035 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create DAO on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpawqdyidrive-2\nuxeo-drive-conf\ndrive_0fbbf08f253c11e7886e080027181249.db
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,036 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Create main connexion on C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpawqdyidrive-2\nuxeo-drive-conf\ndrive_0fbbf08f253c11e7886e080027181249.db (dir exists: 1 / file exists: 0)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,049 3908 3176 TRACE    nxdrive.engine.dao.sqlite Vacuum sqlite
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,053 3908 3176 TRACE    nxdrive.engine.dao.sqlite Vacuum sqlite finished
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,059 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,059 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzI6ZjFkODdl'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,102 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Windows+Desktop&revoke=false&deviceId=0f809540253c11e7893f080027181249&permission=ReadWrite with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzI6ZjFkODdl'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,111 3908 3176 TRACE    nxdrive.client.base_automation_client Got token '540759bf-b07a-4981-aaeb-0a0fafa2bb5d' with cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,121 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': '540759bf-b07a-4981-aaeb-0a0fafa2bb5d', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'}, cookies [] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,131 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo' with cookies []: '{"serverVersion":"9.2-SNAPSHOT","updateSiteURL":"http://community.nuxeo.com/static/drive/","betaUpdateSiteURL":"http://community.nuxeo.com/static/drive-tests/"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,131 3908 3176 DEBUG    nxdrive.engine.engine Fetched update info for engine [localhost] from server http://localhost:8080/nuxeo/: {u'serverVersion': u'9.2-SNAPSHOT', u'updateSiteURL': u'http://community.nuxeo.com/static/drive/', u'betaUpdateSiteURL': u'http://community.nuxeo.com/static/drive-tests/'}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,148 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,148 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': '540759bf-b07a-4981-aaeb-0a0fafa2bb5d', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,180 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': '540759bf-b07a-4981-aaeb-0a0fafa2bb5d', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'}, cookies [Cookie(version=0, name='X-Authentication-Token', value='540759bf-b07a-4981-aaeb-0a0fafa2bb5d', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,187 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies [Cookie(version=0, name='X-Authentication-Token', value='540759bf-b07a-4981-aaeb-0a0fafa2bb5d', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]: '{"canScrollDescendants":false,"canCreateChild":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","lockInfo":null,"creationDate":184,"creator":"system","folder":true,"parentId":null,"canRename":false,"canDelete":false,"lastContributor":"system","lastModificationDate":184,"userName":"driveuser_2"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,187 3908 3176 TRACE    nxdrive.engine.dao.sqlite Will not push pair: locally_created, pair=None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,190 3908 3176 TRACE    nxdrive.engine.dao.sqlite Updating remote state for row = StateRow[1](Local: u'/', Remote: None, Local state: created, Remote state: unknown, State: locally_created) with info = RemoteFileInfo(name=u'Nuxeo Drive', uid=u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#', parent_uid=None, path=u'/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#', folderish=True, last_modification_time=datetime.datetime(1970, 1, 1, 1, 0), last_contributor=u'system', digest=None, digest_algorithm=None, download_url=None, can_rename=False, can_delete=False, can_update=False, can_create_child=False, lock_owner=None, lock_created=None, can_scroll_descendants=False) (force: False)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,193 3908 3176 TRACE    nxdrive.engine.dao.sqlite Will not push pair: locally_created, pair=None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,194 3908 3176 TRACE    nxdrive.client.local_client Setting xattr ndriveroot with value 'http://localhost:8080/nuxeo/|driveuser_2|0f809540253c11e7893f080027181249|0fbbf08f253c11e7886e080027181249' on u'\\\\?\\C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpawqdyidrive-2\\Nuxeo Drive'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,194 3908 3176 TRACE    nxdrive.client.local_client Setting xattr ndrive with value 'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#' on u'\\\\?\\C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpawqdyidrive-2\\Nuxeo Drive'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,194 3908 3176 TRACE    nxdrive.engine.dao.sqlite Try to synchronize state for [local_path=/, remote_name=None, version=0] with version=0
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,197 3908 3176 DEBUG    nxdrive.engine.dao.sqlite Queuing 0 children of 'StateRow[1](Local: u'/', Remote: None, Local state: created, Remote state: unknown, State: locally_created)'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,213 3908 3176 DEBUG    nxdrive.engine.watcher.local_watcher Windows detected so delete event will be delayed by 2000ms
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,221 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,221 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,253 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"params": {"value": "5deda0ba-f010-4eb6-bb00-1387d58116fa"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,265 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"5deda0ba-f010-4eb6-bb00-1387d58116fa","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"ae86ff96-cc87-4964-90c1-b11d9c39c6b9","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632554737","title":"Nuxeo Drive Test Workspace","lastModified":"2017-04-19T20:09:14.737Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:themePage":"workspace","webc:logo":null,"webc:name":null,"webc:email":null,"webc:welcomeMedia":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:content":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2017-04-19T20:09:14.737Z","dc:lastContributor":"Administrator","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:14.737Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,269 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,269 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzI6ZjFkODdl'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,303 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzI6ZjFkODdl'}, cookies [] and JSON payload '{"params": {"value": "5deda0ba-f010-4eb6-bb00-1387d58116fa"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,311 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"5deda0ba-f010-4eb6-bb00-1387d58116fa","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"ae86ff96-cc87-4964-90c1-b11d9c39c6b9","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632554737","title":"Nuxeo Drive Test Workspace","lastModified":"2017-04-19T20:09:14.737Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:themePage":"workspace","webc:logo":null,"webc:name":null,"webc:email":null,"webc:welcomeMedia":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:content":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2017-04-19T20:09:14.737Z","dc:lastContributor":"Administrator","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:14.737Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,315 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,315 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,348 3908 3176 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,349 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzI6ZjFkODdl'} and cookies []
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,384 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"input": "doc:5deda0ba-f010-4eb6-bb00-1387d58116fa", "params": {"enable": true}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,464 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] has content-type ''
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,466 3908 3176 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzI6ZjFkODdl'}, cookies [] and JSON payload '{"input": "doc:5deda0ba-f010-4eb6-bb00-1387d58116fa", "params": {"enable": true}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,525 3908 3176 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] has content-type ''
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:15,535 3908 2464 DEBUG    tests.common_unit_test UnitTest thread started
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,536 3908 2464 TRACE    nxdrive.client.local_client Setting xattr drive-fs-test with value 'NXDRIVE_VERIFICATION' on u'\\\\?\\C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpxvzuhadrive-1\\Nuxeo Drive'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,540 3908 2464 TRACE    nxdrive.client.local_client Removing xattr drive-fs-test from \\?\C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\Nuxeo Drive
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,546 3908 2464 DEBUG    nxdrive.engine.engine Engine 0f9fb600253c11e7a979080027181249 starting
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,546 3908 2464 DEBUG    tests.common_unit_test Wait for sync
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,548 3908 1780 DEBUG    nxdrive.engine.workers Thread LocalWatcher(1780) start
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,549 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForElasticsearchCompletion with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,555 3908 1780 DEBUG    nxdrive.engine.watcher.local_watcher Watching FS modification on : C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\Nuxeo Drive
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,562 3908 1780 INFO     nxdrive.engine.watcher.local_watcher Stopping FS Observer thread
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,565 3908 1780 WARNING  nxdrive.engine.watcher.local_watcher Can't join FS observer : RuntimeError('cannot join thread before it is started',)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,565 3908 1780 WARNING  nxdrive.engine.workers Thread LocalWatcher(1780) ended with exception : error("can't start new thread",)
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,565 3908 1780 ERROR    nxdrive.engine.workers can't start new thread
20:10:50 [WINSLAVE] [INFO]      [exec] Traceback (most recent call last):
20:10:50 [WINSLAVE] [INFO]      [exec]   File "C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\sources\nuxeo-drive-client\nxdrive\engine\workers.py", line 179, in run
20:10:50 [WINSLAVE] [INFO]      [exec]     self._execute()
20:10:50 [WINSLAVE] [INFO]      [exec]   File "C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\sources\nuxeo-drive-client\nxdrive\engine\watcher\local_watcher.py", line 111, in _execute
20:10:50 [WINSLAVE] [INFO]      [exec]     self._setup_watchdog()
20:10:50 [WINSLAVE] [INFO]      [exec]   File "C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\sources\nuxeo-drive-client\nxdrive\engine\watcher\local_watcher.py", line 552, in _setup_watchdog
20:10:50 [WINSLAVE] [INFO]      [exec]     self._observer.start()
20:10:50 [WINSLAVE] [INFO]      [exec]   File "C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\deploy-dir\drive-2.7.13-python\watchdog\observers\api.py", line 256, in start
20:10:50 [WINSLAVE] [INFO]      [exec]     super(BaseObserver, self).start()
20:10:50 [WINSLAVE] [INFO]      [exec]   File "C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\deploy-dir\drive-2.7.13-python\watchdog\utils\__init__.py", line 112, in start
20:10:50 [WINSLAVE] [INFO]      [exec]     threading.Thread.start(self)
20:10:50 [WINSLAVE] [INFO]      [exec]   File "C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\deploy-dir\drive-2.7.13-python\lib\threading.py", line 736, in start
20:10:50 [WINSLAVE] [INFO]      [exec]     _start_new_thread(self.__bootstrap, ())
20:10:50 [WINSLAVE] [INFO]      [exec] error: can't start new thread
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:16,592 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForElasticsearchCompletion' with cookies [] has content-type ''
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,624 3908 2464 WARNING  tests.common_unit_test Wait for sync timeout has expired
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,625 3908 2464 TRACE    nxdrive.engine.dao.sqlite Cache Syncing count incorrect should be 0 was 1
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,627 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/", "params": {"type": "Folder", "name": "test", "properties": "dc:title=test"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,661 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"1e9d81b4-cd3c-46f1-8abb-b772ebe5e719","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/test","type":"Folder","state":"project","parentRef":"5deda0ba-f010-4eb6-bb00-1387d58116fa","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632586640","title":"test","lastModified":"2017-04-19T20:09:46.640Z","properties":{"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"driveuser_1","dc:modified":"2017-04-19T20:09:46.640Z","dc:lastContributor":"driveuser_1","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:46.640Z","dc:title":"test","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["driveuser_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,664 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/", "params": {"type": "Folder", "name": "Test", "properties": "dc:title=Test"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,693 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"f4a198e0-83c1-4887-b977-49e5a8e04834","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test","type":"Folder","state":"project","parentRef":"5deda0ba-f010-4eb6-bb00-1387d58116fa","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632586676","title":"Test","lastModified":"2017-04-19T20:09:46.676Z","properties":{"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"driveuser_1","dc:modified":"2017-04-19T20:09:46.676Z","dc:lastContributor":"driveuser_1","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:46.676Z","dc:title":"Test","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["driveuser_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,694 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/test", "params": {"type": "File", "name": "test.txt", "properties": "dc:title=test.txt"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,713 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"333a9324-67ad-4f7b-bbff-cd9f75da0731","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/test/test.txt","type":"File","state":"project","parentRef":"1e9d81b4-cd3c-46f1-8abb-b772ebe5e719","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632586701","title":"test.txt","lastModified":"2017-04-19T20:09:46.701Z","properties":{"uid:uid":null,"uid:major_version":0,"uid:minor_version":0,"file:content":null,"common:icon-expanded":null,"common:icon":"/icons/file.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"driveuser_1","dc:modified":"2017-04-19T20:09:46.701Z","dc:lastContributor":"driveuser_1","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:46.701Z","dc:title":"test.txt","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["driveuser_1"],"dc:source":null,"dc:publisher":null,"relatedtext:relatedtextresources":[]},"facets":["Versionable","Publishable","Commentable","HasRelatedText","Downloadable"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,726 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/api/v1/upload' with cookies []: '{"batchId":"batchId-8a938056-6c70-4fb2-ad67-16e6d558ca44"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,726 3908 2464 TRACE    nxdrive.utils      Guessed mime type 'text/plain' for 'test.txt'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,726 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/api/v1/upload/batchId-8a938056-6c70-4fb2-ad67-16e6d558ca44/0 with headers {'Content-Length': 4L, 'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': 'driveuser_1', 'X-File-Size': 4L, 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2', 'Cache-Control': 'no-cache', 'User-Agent': 'Nuxeo Drive/2.4.0', 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'test.txt'} and cookies [] for file C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpfmnmgm-nxdrive-uploads\tmpnsfpwv-nxdrive-file-to-upload
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,737 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/api/v1/upload/batchId-8a938056-6c70-4fb2-ad67-16e6d558ca44/0' with cookies []: '{"uploaded":"true","fileIdx":"0","uploadedSize":"4","uploadType":"normal","batchId":"batchId-8a938056-6c70-4fb2-ad67-16e6d558ca44"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,737 3908 2464 TRACE    nxdrive.client.base_automation_client Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpfmnmgm-nxdrive-uploads\tmpnsfpwv-nxdrive-file-to-upload
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,739 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/api/v1/upload/batchId-8a938056-6c70-4fb2-ad67-16e6d558ca44/0/execute/Blob.Attach with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"params": {"document": "333a9324-67ad-4f7b-bbff-cd9f75da0731"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,763 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/api/v1/upload/batchId-8a938056-6c70-4fb2-ad67-16e6d558ca44/0/execute/Blob.Attach' with cookies [] has content-type 'text/plain'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,765 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test", "params": {"type": "File", "name": "test_2.txt", "properties": "dc:title=test_2.txt"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,796 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"57ebfc77-1437-460c-9e53-101ddaad0979","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test/test_2.txt","type":"File","state":"project","parentRef":"f4a198e0-83c1-4887-b977-49e5a8e04834","isCheckedOut":true,"isVersion":false,"isProxy":false,"changeToken":"1492632586773","title":"test_2.txt","lastModified":"2017-04-19T20:09:46.773Z","properties":{"uid:uid":null,"uid:major_version":0,"uid:minor_version":0,"file:content":null,"common:icon-expanded":null,"common:icon":"/icons/file.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"driveuser_1","dc:modified":"2017-04-19T20:09:46.773Z","dc:lastContributor":"driveuser_1","dc:rights":null,"dc:expired":null,"dc:format":null,"dc:created":"2017-04-19T20:09:46.773Z","dc:title":"test_2.txt","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["driveuser_1"],"dc:source":null,"dc:publisher":null,"relatedtext:relatedtextresources":[]},"facets":["Versionable","Publishable","Commentable","HasRelatedText","Downloadable"]}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,805 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/api/v1/upload' with cookies []: '{"batchId":"batchId-e3b30828-d9b3-45b8-8c9f-43d31b125db1"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,806 3908 2464 TRACE    nxdrive.utils      Guessed mime type 'text/plain' for 'test_2.txt'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,806 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/api/v1/upload/batchId-e3b30828-d9b3-45b8-8c9f-43d31b125db1/0 with headers {'Content-Length': 4L, 'X-Client-Version': '2.4.0', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': 'driveuser_1', 'X-File-Size': 4L, 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2', 'Cache-Control': 'no-cache', 'User-Agent': 'Nuxeo Drive/2.4.0', 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'test_2.txt'} and cookies [] for file C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpfmnmgm-nxdrive-uploads\tmpiv9ld1-nxdrive-file-to-upload
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,816 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/api/v1/upload/batchId-e3b30828-d9b3-45b8-8c9f-43d31b125db1/0' with cookies []: '{"uploaded":"true","fileIdx":"0","uploadedSize":"4","uploadType":"normal","batchId":"batchId-e3b30828-d9b3-45b8-8c9f-43d31b125db1"}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,816 3908 2464 TRACE    nxdrive.client.base_automation_client Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpfmnmgm-nxdrive-uploads\tmpiv9ld1-nxdrive-file-to-upload
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,816 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/api/v1/upload/batchId-e3b30828-d9b3-45b8-8c9f-43d31b125db1/0/execute/Blob.Attach with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic ZHJpdmV1c2VyXzE6M2E0OWY2'}, cookies [] and JSON payload '{"params": {"document": "57ebfc77-1437-460c-9e53-101ddaad0979"}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,839 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/api/v1/upload/batchId-e3b30828-d9b3-45b8-8c9f-43d31b125db1/0/execute/Blob.Attach' with cookies [] has content-type 'text/plain'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,841 3908 2464 DEBUG    tests.common_unit_test Wait for sync
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:46,842 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForElasticsearchCompletion with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:09:49,023 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForElasticsearchCompletion' with cookies [] has content-type ''
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,056 3908 2464 WARNING  tests.common_unit_test Wait for sync timeout has expired
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,059 3908 2464 DEBUG    nxdrive.report     Create report 'tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync.test_dedup_folders-win32'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,062 3908 2464 DEBUG    nxdrive.report     Manager metrics: {'tracking': True, 'python_version': '2.7.13', 'appname': 'Nuxeo Drive', 'auto_update': True, 'qt_version': '4.8.7', 'tracker_id': 'UA-81135-23', 'platform': 'Windows', 'version': '2.4.0', 'pyqt_version': '4.11.4', 'auto_start': True, 'beta_channel': False, 'device_id': '0f7cc4b0253c11e7a341080027181249'}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,068 3908 2464 DEBUG    nxdrive.report     Engine metrics: {'files_size': 0, 'sync_files': 0, 'syncing': 0, 'error_files': 0, 'conflicted_files': 0, 'sync_folders': 1, 'invalid_credentials': False, 'unsynchronized_files': 0}
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,851 3908 2464 DEBUG    tests.common_unit_test Report generated in 'C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA/sources\tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync.test_dedup_folders-win32'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,851 3908 2464 DEBUG    tests.common_unit_test TearDown unit test
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,851 3908 2464 DEBUG    nxdrive.engine.queue_manager Suspending queue
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:19,851 3908 2464 DEBUG    nxdrive.engine.engine Engine 0f9fb600253c11e7a979080027181249 stopping
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,851 3908 2464 WARNING  nxdrive.engine.engine Thread is not responding - terminate it
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,852 3908 2464 DEBUG    nxdrive.engine.engine Engine 0f9fb600253c11e7a979080027181249 stopped
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,861 3908 2464 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,861 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'344987ac-b96d-4116-a4c8-7d79785def17', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'} and cookies [Cookie(version=0, name='X-Authentication-Token', value='344987ac-b96d-4116-a4c8-7d79785def17', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,901 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Windows+Desktop&revoke=true&deviceId=0f7cc4b0253c11e7a341080027181249&permission=ReadWrite with headers {'X-Authentication-Token': u'344987ac-b96d-4116-a4c8-7d79785def17', 'X-Device-Id': '0f7cc4b0253c11e7a341080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'} and cookies [Cookie(version=0, name='X-Authentication-Token', value='344987ac-b96d-4116-a4c8-7d79785def17', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,911 3908 2464 TRACE    nxdrive.client.base_automation_client Got token 'Token revoked for userName driveuser_1, applicationName Nuxeo Drive and deviceId 0f7cc4b0253c11e7a341080027181249.' with cookies [Cookie(version=0, name='X-Authentication-Token', value='344987ac-b96d-4116-a4c8-7d79785def17', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,913 3908 2464 DEBUG    nxdrive.engine.dao.sqlite Disposing sqlite database u'C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpxvzuhadrive-1\\nuxeo-drive-conf\\ndrive_0f9fb600253c11e7a979080027181249.db'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,915 3908 2464 DEBUG    nxdrive.engine.engine Remove DB file C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpxvzuhadrive-1\nuxeo-drive-conf\ndrive_0f9fb600253c11e7a979080027181249.db
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,921 3908 2464 DEBUG    nxdrive.engine.dao.sqlite Disposing sqlite database u'C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpxvzuhadrive-1\\nuxeo-drive-conf\\manager.db'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,923 3908 2464 DEBUG    nxdrive.engine.queue_manager Suspending queue
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,923 3908 2464 DEBUG    nxdrive.engine.engine Engine 0fbbf08f253c11e7886e080027181249 stopping
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,924 3908 2464 DEBUG    nxdrive.engine.engine Engine 0fbbf08f253c11e7886e080027181249 stopped
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,930 3908 2464 TRACE    nxdrive.client.base_automation_client Proxy configuration: System, effective proxy list: None
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,931 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'540759bf-b07a-4981-aaeb-0a0fafa2bb5d', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'} and cookies [Cookie(version=0, name='X-Authentication-Token', value='540759bf-b07a-4981-aaeb-0a0fafa2bb5d', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,961 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Windows+Desktop&revoke=true&deviceId=0f809540253c11e7893f080027181249&permission=ReadWrite with headers {'X-Authentication-Token': u'540759bf-b07a-4981-aaeb-0a0fafa2bb5d', 'X-Device-Id': '0f809540253c11e7893f080027181249', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'driveuser_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.4.0'} and cookies [Cookie(version=0, name='X-Authentication-Token', value='540759bf-b07a-4981-aaeb-0a0fafa2bb5d', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,970 3908 2464 TRACE    nxdrive.client.base_automation_client Got token 'Token revoked for userName driveuser_2, applicationName Nuxeo Drive and deviceId 0f809540253c11e7893f080027181249.' with cookies [Cookie(version=0, name='X-Authentication-Token', value='540759bf-b07a-4981-aaeb-0a0fafa2bb5d', port=None, port_specified=False, domain=u'localhost.local', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=True, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,970 3908 2464 DEBUG    nxdrive.engine.dao.sqlite Disposing sqlite database u'C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpawqdyidrive-2\\nuxeo-drive-conf\\ndrive_0fbbf08f253c11e7886e080027181249.db'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,971 3908 2464 DEBUG    nxdrive.engine.engine Remove DB file C:\Jenkins\0ebd1d51\workspace\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\tmp\tmpawqdyidrive-2\nuxeo-drive-conf\ndrive_0fbbf08f253c11e7886e080027181249.db
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,974 3908 2464 DEBUG    nxdrive.engine.dao.sqlite Disposing sqlite database u'C:\\Jenkins\\0ebd1d51\\workspace\\Drive_FT-drive_master-CUACR5UOIAO62W7K2CAAQ7UISS5UUL3SF5V2PSVOUZC4CRBQLRIA\\tmp\\tmpawqdyidrive-2\\nuxeo-drive-conf\\manager.db'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:24,976 3908 2464 TRACE    nxdrive.client.base_automation_client Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.TearDownIntegrationTests with headers {'X-Client-Version': '2.4.0', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.4.0', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:25,042 3908 2464 TRACE    nxdrive.client.base_automation_client Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.TearDownIntegrationTests' with cookies [] has content-type ''
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:37,262 3908 2464 DEBUG    tests.common_unit_test Profiler Report generated in 'yappi\tests.test_synchronization_dedup.TestDedupInsensitiveCaseSync.test_dedup_folders-yappi-fcts'
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:37,637 3908 2464 DEBUG    tests.common_unit_test UnitTest thread finished
20:10:50 [WINSLAVE] [INFO]      [exec] 2017-04-19 22:10:37,641 3908 3176 DEBUG    tests.common_unit_test UnitTest run finished
20:10:50 [WINSLAVE] [INFO]      [exec] !!!!!!!!!!!!!!!!!!! Interrupted: stopping after 1 failures !!!!!!!!!!!!!!!!!!!!
20:10:50 [WINSLAVE] [INFO]      [exec] ============= 1 failed, 211 passed, 18 skipped in 5359.65 seconds =============

We could enumerate the runinng threads in case of failure with https://docs.python.org/2/library/threading.html#threading.enumerate

Attachments

Activity

People

Assignee:

Mickaël Schoentgen

Reporter:

Antoine Taillefer

Participants:

Antoine Taillefer, Jenkins, Mickaël Schoentgen

Votes:

0 Vote for this issue

Watchers:

3 Start watching this issue

Dates

Created:

2017-04-20 09:25

Updated:

2017-10-27 09:42

Resolved:

2017-10-27 09:42