Error: Panic: net/http: abort Handler

Hello! I try to start a session on nodes, a grid with a basic config, but I get an error ...

INFO[1550] requested session with params: {"desiredCapabilities":{"browserName": "chrome"}} 
INFO[1551] register SessionID: 4b8f95d6cb9cb32f0a962146e229af3e on node 192.168.1.200:14385 
ERRO[1551] Panic: net/http: abort Handler
goroutine 959 [running]:
runtime/debug.Stack(0xc0004e15b8, 0x13af380, 0xc00007ecc0)
	/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d
github.com/qa-dev/jsonwire-grid/middleware.(*Wrap).Do.func1.1(0xc00009fd60)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/middleware/wrap.go:32 +0x57
panic(0x13af380, 0xc00007ecc0)
	/usr/local/opt/go/libexec/src/runtime/panic.go:679 +0x1b2
net/http/httputil.(*ReverseProxy).ServeHTTP(0xc000113180, 0x1795c40, 0xc00034bce0, 0xc0001c4700)
	/usr/local/opt/go/libexec/src/net/http/httputil/reverseproxy.go:299 +0x14c9
github.com/qa-dev/jsonwire-grid/handlers.(*CreateSession).tryCreateSession(0xc00009fe00, 0xc0001c4700, 0xc0004e1a70, 0x13, 0xc0003788a8, 0x1)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/handlers/createSession.go:92 +0x395
github.com/qa-dev/jsonwire-grid/handlers.(*CreateSession).ServeHTTP(0xc00009fe00, 0x179bc00, 0xc0001d37a0, 0xc0001c4700)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/handlers/createSession.go:60 +0x3f0
github.com/qa-dev/jsonwire-grid/middleware.(*Wrap).Do.func1(0x179bc00, 0xc0001d37a0, 0xc0001c4700)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/middleware/wrap.go:36 +0x9a
net/http.HandlerFunc.ServeHTTP(0xc00009fe20, 0x179bc00, 0xc0001d37a0, 0xc0001c4700)
	/usr/local/opt/go/libexec/src/net/http/server.go:2007 +0x44
net/http.(*ServeMux).ServeHTTP(0x2256940, 0x179bc00, 0xc0001d37a0, 0xc0001c4700)
	/usr/local/opt/go/libexec/src/net/http/server.go:2387 +0x1bd
net/http.serverHandler.ServeHTTP(0xc0000e2000, 0x179bc00, 0xc0001d37a0, 0xc0001c4700)
	/usr/local/opt/go/libexec/src/net/http/server.go:2802 +0xa4
net/http.(*conn).serve(0xc0004a1220, 0x17a02c0, 0xc00030d7c0)
	/usr/local/opt/go/libexec/src/net/http/server.go:1890 +0x875
created by net/http.(*Server).Serve
	/usr/local/opt/go/libexec/src/net/http/server.go:2927 +0x38e  component=middlewareWrap

But the session starts and displays in "/grid/status"

{
  "node_list": [
    {
      "key": "192.168.1.200:14385",
      "type": "persistent",
      "address": "192.168.1.200:14385",
      "status": "busy",
      "session_id": "4b8f95d6cb9cb32f0a962146e229af3e",
      "updated": 1580904729,
      "registered": 1580903287,
      "capabilities_list": [
        {
          "browserName": "chrome",
          "platform": "LINUX",
          "platformName": "LINUX",
          "seleniumProtocol": "WebDriver",
          "server:CONFIG_UUID": "c4b3a193-104d-4622-b906-ef49be0220f0"
        }
      ]
    },
    {
      "key": "192.168.1.200:7409",
      "type": "persistent",
      "address": "192.168.1.200:7409",
      "status": "available",
      "session_id": "873f8c774564d5adb879a0b08cd8287f",
      "updated": 1580904678,
      "registered": 1580903312,
      "capabilities_list": [
        {
          "browserName": "chrome",
          "platform": "LINUX",
          "platformName": "LINUX",
          "seleniumProtocol": "WebDriver",
          "server:CONFIG_UUID": "46c83736-af91-4e2f-a26a-e2c64e8c0693"
        }
      ]
    },
    {
      "key": "192.168.1.200:27227",
      "type": "persistent",
      "address": "192.168.1.200:27227",
      "status": "available",
      "session_id": "b82d1b538d44c00a585de537cc602a17",
      "updated": 1580904678,
      "registered": 1580903326,
      "capabilities_list": [
        {
          "browserName": "chrome",
          "platform": "LINUX",
          "platformName": "LINUX",
          "seleniumProtocol": "WebDriver",
          "server:CONFIG_UUID": "3ac6db5d-522a-4970-8fec-a83f183836fd"
        }
      ]
    }
  ],
  "config": {
    "logger": {
      "level": "debug"
    },
    "db": {
      "implementation": "local",
      "connection": ""
    },
    "grid": {
      "client_type": "selenium",
      "port": 4444,
      "strategy_list": [
        {
          "params": null,
          "type": "persistent",
          "limit": 0,
          "node_list": null
        }
      ],
      "busy_node_duration": "15m",
      "reserved_node_duration": "5m"
    }
  }
}

But when requesting "/grid/session/info?sessionid=4b8f95d6cb9cb32f0a962146e229af3e" again, errors ...

ERRO[1743] Can't find node by session[info], storage: node not found  
INFO[1743] session info not found in node pool: Can't find node by session[info], storage: node not found  

What am I doing wrong?

using selenium-server-standalone-3.141.59.jar as node

[andrskom]

Hi, maybe session had already closed when you tried to request info? We'll try to repeat your case.

[sohardco]

Hi there. I've experienced same issue on two latest versions 0.5.0 and 0.4.0 while trying to run my appium tests. Everything seems to be working fine from ver. 0.3.0 to 0.3.2 tho.
When upgrading to recent versions jsonwire-grid drops session after my appium node responds with:

[debug] [W3C (334de6e6)] Responding to client with driver.createSession() result: {
  "capabilities": {
    "platform": "LINUX",
    "webStorageEnabled": false,
    "takesScreenshot": true,
    "javascriptEnabled": true,
    "databaseEnabled": false,
    "networkConnectionEnabled": true,
    "locationContextEnabled": false,
    "warnings": {},
    "desired": {
      "platformName": "Android",
      "deviceName": "Mi MIX 2S",
      "platformVersion": "10",
      "orientation": "PORTRAIT",
      "language": "en",
      "locale": "US",
      "automationName": "UiAutomator2",
      "app": "path/to/apk",
      "noReset": false,
      "newCommandTimeout": 240,
      "udid": "5334679f"
    },
    "platformName": "Android",
    "deviceName": "5334679f",
    "platformVersion": "10",
    "orientation": "PORTRAIT",
    "language": "en",
    "locale": "US",
    "automationName": "UiAutomator2",
    "app": "path/to/apk",
    "noReset": false,
    "newCommandTimeout": 240,
    "udid": "5334679f",
    "deviceUDID": "5334679f",
    "appPackage": "com.package.name",
    "deviceApiLevel": 29,
    "deviceScreenSize": "1080x2160",
    "deviceScreenDensity": 440
  }
}

At the same time jsonwire-grid debug log looks like

INFO[0042] register SessionID: 08bc8615-69cc-4c94-a9d4-15108ecc31e1 on node 127.0.0.1:4727
ERRO[0042] Panic: net/http: abort Handler
goroutine 88 [running]:
runtime/debug.Stack(0xc00059b5b8, 0x1fb53e0, 0xc000032dc0)
	/usr/local/opt/go/libexec/src/runtime/debug/stack.go:24 +0x9d
github.com/qa-dev/jsonwire-grid/middleware.(*Wrap).Do.func1.1(0xc00000fc60)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/middleware/wrap.go:32 +0x57
panic(0x1fb53e0, 0xc000032dc0)
	/usr/local/opt/go/libexec/src/runtime/panic.go:679 +0x1b2
net/http/httputil.(*ReverseProxy).ServeHTTP(0xc0000d0410, 0x239d7e0, 0xc000338de0, 0xc00060c700)
	/usr/local/opt/go/libexec/src/net/http/httputil/reverseproxy.go:299 +0x14c9
github.com/qa-dev/jsonwire-grid/handlers.(*CreateSession).tryCreateSession(0xc00000fce0, 0xc00060c700, 0xc000523a70, 0x13, 0xc0001aed90, 0x1)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/handlers/createSession.go:92 +0x395
github.com/qa-dev/jsonwire-grid/handlers.(*CreateSession).ServeHTTP(0xc00000fce0, 0x23a37a0, 0xc000248380, 0xc00060c700)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/handlers/createSession.go:60 +0x3f0
github.com/qa-dev/jsonwire-grid/middleware.(*Wrap).Do.func1(0x23a37a0, 0xc000248380, 0xc00060c700)
	/Users/mapodtserkovskiy/gopath/src/github.com/qa-dev/jsonwire-grid/middleware/wrap.go:36 +0x9a
net/http.HandlerFunc.ServeHTTP(0xc00000fd00, 0x23a37a0, 0xc000248380, 0xc00060c700)
	/usr/local/opt/go/libexec/src/net/http/server.go:2007 +0x44
net/http.(*ServeMux).ServeHTTP(0x2e66900, 0x23a37a0, 0xc000248380, 0xc00060c700)
	/usr/local/opt/go/libexec/src/net/http/server.go:2387 +0x1bd
net/http.serverHandler.ServeHTTP(0xc0006142a0, 0x23a37a0, 0xc000248380, 0xc00060c700)
	/usr/local/opt/go/libexec/src/net/http/server.go:2802 +0xa4
net/http.(*conn).serve(0xc00014f900, 0x23a7ea0, 0xc0001330c0)
	/usr/local/opt/go/libexec/src/net/http/server.go:1890 +0x875
created by net/http.(*Server).Serve
	/usr/local/opt/go/libexec/src/net/http/server.go:2927 +0x38e  component=middlewareWrap
INFO[0042] requested session with params: {"capabilities":{"alwaysMatch":{"platformName":"Android","deviceName":"Mi MIX 2S","platformVersion":"10","orientation":"PORTRAIT","language":"en","locale":"US","automationName":"UiAutomator2","app":"/Users/yaroslavmaistrenkov/Documents/native-app-automation-tests/apps/FavoritComUa_v.1.76.6.apk","noReset":false,"newCommandTimeout":24000,"udid":"5334679f"},"firstMatch":[{}]},"desiredCapabilities":{"platformName":"Android","deviceName":"Mi MIX 2S","platformVersion":"10","orientation":"PORTRAIT","language":"en","locale":"US","automationName":"UiAutomator2","app":"/Users/yaroslavmaistrenkov/Documents/native-app-automation-tests/apps/FavoritComUa_v.1.76.6.apk","noReset":false,"newCommandTimeout":24000,"udid":"5334679f"}}
ERRO[0042] reserve node in storage, storage: node not found
ERRO[0042] Can't reserve available node, strategy: not found available nodes

and if we go to grid/status we see:

{
  "node_list": [
    {
      "key": "127.0.0.1:4727",
      "type": "persistent",
      "address": "127.0.0.1:4727",
      "status": "busy",
      "session_id": "08bc8615-69cc-4c94-a9d4-15108ecc31e1",
      "updated": 1599490545,
      "registered": 1599490516,
      "capabilities_list": [
        {
          "deviceName": "Mi MIX 2S",
          "maxInstances": 1,
          "platform": "ANDROID",
          "platformName": "Android",
          "platformVersion": "10"
        }
      ]
    }
  ],
  "config": {
    "logger": {
      "level": "debug"
    },
    "db": {
      "implementation": "local",
      "connection": ""
    },
    "grid": {
      "client_type": "selenium",
      "port": 4444,
      "strategy_list": [
        {
          "params": null,
          "type": "persistent",
          "limit": 0,
          "node_list": null
        }
      ],
      "busy_node_duration": "15m",
      "reserved_node_duration": "5m"
    }
  }
}