Error message from Selenium(?) is opaque. How do I find responsible code?

Support
1

I am simulating a pinch/zoom with W3CActions. It all works well, but on releasing the actions (await driver.releaseW3CActions();) there is a error mesage in the terminal an execution stops.

I am not sure how to interpret the error message. I cannot see any reference to what the “UnknownCommand” [sic] is.

How should these errors be interpreted?

The offending code:

    var actions = new wd.W3CActions(driver);

    var touchInput = actions.addTouchInput();
    touchInput.pointerMove({duration: 0, x: 518, y: 205});
    touchInput.pointerDown({button: 0});
    touchInput.pause({duration: 500});
    touchInput.pointerMove({duration: 1000, origin: 'pointer', x: -50, y: 205});
    touchInput.pointerUp({button: 0});
    
    var secondTouchInput = actions.addTouchInput();
    secondTouchInput.pointerMove({duration: 0, x: 682, y: 305});
    secondTouchInput.pointerDown({button: 0});
    secondTouchInput.pause({duration: 300});
    secondTouchInput.pointerMove({duration: 1000, origin: 'pointer', x: 50, y: 205});
    secondTouchInput.pointerUp({button: 0});   
    await actions.perform();

    await driver.releaseW3CActions();

The error message I do not understand. There is a stack trace here but it is not routed in my code, as far as I can tell.

Error: [releaseW3CActions()] Error response status: 9, , UnknownCommand - The requested resource could not be found, or a request was received using an HTTP method that is not supported by the mapped resource. Selenium error: The requested resource could not be found, or a request was received using an HTTP method that is not supported by the mapped resource
    at exports.newError (/Users/user/node_modules/wd/lib/utils.js:152:13)
    at /Users/user/node_modules/wd/lib/callbacks.js:94:19
    at /Users/user/node_modules/wd/lib/webdriver.js:205:5
    at Request._callback (/Users/user/node_modules/wd/lib/http-utils.js:89:7)
    at Request.self.callback (/Users/user/node_modules/request/request.js:185:22)
    at Request.emit (node:events:394:28)
    at Request.<anonymous> (/Users/user/node_modules/request/request.js:1161:10)
    at Request.emit (node:events:394:28)
    at IncomingMessage.<anonymous> (/Users/user/node_modules/request/request.js:1083:12)
    at Object.onceWrapper (node:events:513:28) {
  status: 9,
  cause: {
    status: 9,
    value: {
      error: 'unknown command',
      message: 'The requested resource could not be found, or a request was received using an HTTP method that is not supported by the mapped resource',
      stacktrace: ''
    },
    sessionId: '951bf7db-90eb-4152-aa64-8d6c6430cebf'
  },
  inspect: [Function (anonymous)],
  'jsonwire-error': {
    status: 9,
    summary: 'UnknownCommand',
    detail: 'The requested resource could not be found, or a request was received using an HTTP method that is not supported by the mapped resource.'
  }
}
2

I got a bit hopeful when I thought to look at the log. But it gets me no closer. The answer should be in here someplace…

[HTTP] --> POST /wd/hub/session/b821b429-5319-411f-a180-e34daf3ae0ea/actions
[HTTP] {"actions":[{"type":"pointer","id":"finger1","parameters":{"pointerType":"touch"},"actions":[{"type":"pointerMove","duration":0,"x":518,"y":205},{"type":"pointerDown","button":0},{"type":"pause","duration":500},{"type":"pointerMove","duration":1000,"origin":"pointer","x":-50,"y":205},{"type":"pointerUp","button":0}]},{"type":"pointer","id":"finger2","parameters":{"pointerType":"touch"},"actions":[{"type":"pointerMove","duration":0,"x":682,"y":305},{"type":"pointerDown","button":0},{"type":"pause","duration":300},{"type":"pointerMove","duration":1000,"origin":"pointer","x":50,"y":205},{"type":"pointerUp","button":0}]}]}
[MJSONWP (b821b429)] Calling AppiumDriver.performActions() with args: [[{"type":"pointer","id":"finger1","parameters":{"pointerType":"touch"},"actions":[{"type":"pointerMove","duration":0,"x":518,"y":205},{"type":"pointerDown","button":0},{"type":"pause","duration":500},{"type":"pointerMove","duration":1000,"origin":"pointer","x":-50,"y":205},{"type":"pointerUp","button":0}]},{"type":"pointer","id":"finger2","parameters":{"pointerType":"touch"},"actions":[{"type":"pointerMove","duration":0,"x":682,"y":305},{"type":"pointerDown","button":0},{"type":"pause","duration":300},{"type":"pointerMove","duration":1000,"origin":"pointer","x":50,"y":205},{"type":"pointerUp","button":0}]}],"b821b429-5319-411f-a180-e34daf3ae0ea"]
[XCUITest] Executing command 'performActions'
[XCUITest] Received the following W3C actions: [
[XCUITest]   {
[XCUITest]     "type": "pointer",
[XCUITest]     "id": "finger1",
[XCUITest]     "parameters": {
[XCUITest]       "pointerType": "touch"
[XCUITest]     },
[XCUITest]     "actions": [
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 0,
[XCUITest]         "x": 518,
[XCUITest]         "y": 205
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerDown",
[XCUITest]         "button": 0
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pause",
[XCUITest]         "duration": 500
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 1000,
[XCUITest]         "origin": "pointer",
[XCUITest]         "x": -50,
[XCUITest]         "y": 205
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerUp",
[XCUITest]         "button": 0
[XCUITest]       }
[XCUITest]     ]
[XCUITest]   },
[XCUITest]   {
[XCUITest]     "type": "pointer",
[XCUITest]     "id": "finger2",
[XCUITest]     "parameters": {
[XCUITest]       "pointerType": "touch"
[XCUITest]     },
[XCUITest]     "actions": [
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 0,
[XCUITest]         "x": 682,
[XCUITest]         "y": 305
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerDown",
[XCUITest]         "button": 0
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pause",
[XCUITest]         "duration": 300
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 1000,
[XCUITest]         "origin": "pointer",
[XCUITest]         "x": 50,
[XCUITest]         "y": 205
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerUp",
[XCUITest]         "button": 0
[XCUITest]       }
[XCUITest]     ]
[XCUITest]   }
[XCUITest] ]
[XCUITest] Preprocessed actions: [
[XCUITest]   {
[XCUITest]     "type": "pointer",
[XCUITest]     "id": "finger1",
[XCUITest]     "parameters": {
[XCUITest]       "pointerType": "touch"
[XCUITest]     },
[XCUITest]     "actions": [
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 0,
[XCUITest]         "x": 518,
[XCUITest]         "y": 205
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerDown",
[XCUITest]         "button": 0
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pause",
[XCUITest]         "duration": 500
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 1000,
[XCUITest]         "origin": "pointer",
[XCUITest]         "x": -50,
[XCUITest]         "y": 205
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerUp",
[XCUITest]         "button": 0
[XCUITest]       }
[XCUITest]     ]
[XCUITest]   },
[XCUITest]   {
[XCUITest]     "type": "pointer",
[XCUITest]     "id": "finger2",
[XCUITest]     "parameters": {
[XCUITest]       "pointerType": "touch"
[XCUITest]     },
[XCUITest]     "actions": [
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 0,
[XCUITest]         "x": 682,
[XCUITest]         "y": 305
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerDown",
[XCUITest]         "button": 0
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pause",
[XCUITest]         "duration": 300
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerMove",
[XCUITest]         "duration": 1000,
[XCUITest]         "origin": "pointer",
[XCUITest]         "x": 50,
[XCUITest]         "y": 205
[XCUITest]       },
[XCUITest]       {
[XCUITest]         "type": "pointerUp",
[XCUITest]         "button": 0
[XCUITest]       }
[XCUITest]     ]
[XCUITest]   }
[XCUITest] ]
[WD Proxy] Matched '/actions' to command name 'performActions'
[WD Proxy] Proxying [POST /actions] to [POST http://127.0.0.1:8100/session/737497C7-25DD-4F0C-8A6E-74D998736B81/actions] with body: {"actions":[{"type":"pointer","id":"finger1","parameters":{"pointerType":"touch"},"actions":[{"type":"pointerMove","duration":0,"x":518,"y":205},{"type":"pointerDown","button":0},{"type":"pause","duration":500},{"type":"pointerMove","duration":1000,"origin":"pointer","x":-50,"y":205},{"type":"pointerUp","button":0}]},{"type":"pointer","id":"finger2","parameters":{"pointerType":"touch"},"actions":[{"type":"pointerMove","duration":0,"x":682,"y":305},{"type":"pointerDown","button":0},{"type":"pause","duration":300},{"type":"pointerMove","duration":1000,"origin":"pointer","x":50,"y":205},{"type":"pointerUp","button":0}]}]}
[Xcode] 2021-06-21 17:23:05.844212+1200 WebDriverAgentRunner-Runner[39322:4995112] Getting the most recent active application (out of 1 total items)
[Xcode] 
[Xcode]     t =   983.21s Find the Application 'com.quickcustomintelligence.qcislotsviewmodule'
[Xcode] 
[Xcode]     t =   983.21s     Requesting snapshot of accessibility hierarchy for app with pid 39430
[Xcode] 
[Xcode]     t =   983.26s Find the Application 'com.quickcustomintelligence.qcislotsviewmodule'
[Xcode] 
[Xcode]     t =   983.27s     Requesting snapshot of accessibility hierarchy for app with pid 39430
[Xcode] 
[Xcode] 2021-06-21 17:23:07.496225+1200 WebDriverAgentRunner-Runner[39322:4995112] Waiting up to 2s until com.quickcustomintelligence.qcislotsviewmodule is in idle state (including animations)
[Xcode]     t =   984.86s Wait for com.quickcustomintelligence.qcislotsviewmodule to idle
[Xcode] 
[WD Proxy] Got response with status 200: {"value":null,"sessionId":"737497C7-25DD-4F0C-8A6E-74D998736B81"}
[MJSONWP (b821b429)] Responding to client with driver.performActions() result: null
[HTTP] <-- POST /wd/hub/session/b821b429-5319-411f-a180-e34daf3ae0ea/actions 200 1688 ms - 76
[HTTP] 
[HTTP] --> DELETE /wd/hub/session/b821b429-5319-411f-a180-e34daf3ae0ea/actions
[HTTP] {}
[HTTP] No route found for /wd/hub/session/b821b429-5319-411f-a180-e34daf3ae0ea/actions
[HTTP] <-- DELETE /wd/hub/session/b821b429-5319-411f-a180-e34daf3ae0ea/actions 404 2 ms - 262
[HTTP] 
[BaseDriver] Shutting down because we waited 60 seconds for a command
[Appium] Closing session, cause was 'New Command Timeout of 60 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability'
[Appium] Removing session 'b821b429-5319-411f-a180-e34daf3ae0ea' from our master session list
[DevCon Factory] Releasing connections for E697EC67-CD3D-407A-B484-13F43CDEC219 device on any port number
[DevCon Factory] No cached connections have been found
[XCUITest] Not clearing log files. Use `clearSystemFiles` capability to turn on.
[IOSSimulatorLog] Stopping iOS log capture