Run a GraphQL demo server, that replies a static Cylc 8.0a2 workflow query

graphql-demo.js

const express = require('express')
const bodyParser = require('body-parser')
const { graphqlExpress, graphiqlExpress } = require('apollo-server-express')
const { makeExecutableSchema } = require('graphql-tools')
const { PubSub } = require('graphql-subscriptions')
const { createServer } = require('http')
const { SubscriptionServer } = require('subscriptions-transport-ws')
const { execute, subscribe } = require('graphql')

const statuses = [
  'running',
  'held',
  'stopped'
]

// Some fake data
const workflows = [
  {
    id: 'five',
    name: 'five',
    status: 'waiting',
    host: 'localhost',
    port: 1000,
    owner: 'kinow'
  },
  {
    id: 'six',
    name: 'six',
    status: 'stalled',
    host: 'localhost',
    port: 2000,
    owner: 'kinow'
  }
]

// The GraphQL schema in string form
const typeDefs = `
  type Query { workflows: [Workflow] }
  type Subscription { workflows: [Workflow] }
  type Workflow {
    id: String!,
    name: String,
    status: String,
    host: String,
    port: Int,
    owner: String
  }
`

// WebSockets
const pubsub = new PubSub()

// The resolvers
const resolvers = {
  Query: { workflows: () => workflows },
  Subscription: {
    workflows: {
      subscribe: () => pubsub.asyncIterator('workflows')
    }
  }
}

setInterval(() => {
  for (const workflow of workflows) {
    workflow.status = statuses[Math.floor(Math.random() * statuses.length)]
  }
  pubsub.publish('workflows', {
    workflows: workflows
  })
}, 5000)

// Put together a schema
const schema = makeExecutableSchema({
  typeDefs,
  resolvers
})

// Initialize the app
const app = express()

// The GraphQL endpoint
app.use('/graphql', bodyParser.json(), graphqlExpress({ schema }))

// GraphiQL, a visual editor for queries
app.use('/graphiql', graphiqlExpress({
  endpointURL: '/graphql',
  subscriptionEndpoint: 'ws://localhost:3000/subscriptions'
}))

const server = createServer(app)

// Start the server
server.listen(3000, () => {
  // eslint-disable-next-line no-new
  new SubscriptionServer({
    execute,
    subscribe,
    schema: schema
  }, {
    server: server,
    path: '/subscriptions'
  })
  console.log('Go to http://localhost:3000/graphiql to run queries!')
})

// also need to include something in `package.json` like:
// "scripts": {
//   "graphql:serve": "node graphql-demo.js"
//  }

logging_config.json

{
  "logging": {
    "version": 1,
    "disable_existing_loggers": true,
    "formatters": {
      "basic": {
        "format": "%(asctime)s %(name)-12s %(levelname)-8s %(message)s"
      },
      "verbose": {
        "class": "logging.Formatter",
        "datefmt": "%I:%M:%S",
        "format": "%(levelname)-8s; [%(process)d]; %(threadName)s; %(name)-15s; %(module)s:%(funcName)s;%(lineno)d: %(message)s"
      }
    },
    "handlers": {
      "console": {
        "level": "DEBUG",
        "class": "logging.StreamHandler",
        "formatter": "basic",
        "stream" : "ext://sys.stdout"
      },
      "file": {
        "level": "DEBUG",
        "class": "logging.handlers.WatchedFileHandler",
        "formatter": "verbose",
        "filename" : "/tmp/websockets.log",
        "mode": "a",
        "encoding": "utf-8"
      }
    },
    "loggers": {
      "tornado.access": {
        "level": "WARN",
        "handlers": ["console"],
        "propagate": false
      },
      "tornado.application": {
        "level": "WARN",
        "handlers": ["console"],
        "propagate": false
      },
      "cylc.flow": {
        "level": "DEBUG",
        "handlers": ["console"],
        "propagate": false
      },
      "cylc.uiserver": {
        "level": "DEBUG",
        "handlers": ["console"],
        "propagate": false
      },
      "cylc.uiserver.websockets": {
        "level": "DEBUG",
        "handlers": ["file"],
        "propagate": false
      }
    },
    "root": {
      "handlers": ["console"],
      "level": "WARN"
    }
  }
}

websocket.md

How many WebSocket connections?

Each browser tab gets a separate JavaScript WebSocket client. It is also possible to see the connections with lsof.

When the jupyterhub and configurable-http-proxy are running, lsof should show these two listening connections.

$ lsof -p $(ps aux | grep "[c]onfigurable-http-proxy" | awk '{print $2}')
...
node    26484 kinow   20u     IPv6 507887      0t0     TCP *:8000 (LISTEN)
node    26484 kinow   21u     IPv4 507888      0t0     TCP localhost:8001 (LISTEN)

When you open a tab in the browser, you will connect to the configurable-htt-proxy on port 80. The proxy will have a connection to the Tornado application. The Tornado application is given a random port number.

$ netstat -tlnp
...
tcp6       0      0 :::48561                :::*                    LISTEN      5168/python         
tcp6       0      0 :::8000                 :::*                    LISTEN      26484/node 

You can match the pid 5168 from netstat output with what you get in the lsof output, and confirm that's the JupyterHub spawned UI Server on port 48561.

$ lsof -p $(ps aux | grep "[c]onfigurable-http-proxy" | awk '{print $2}')
...
node    26484 kinow   22u     IPv6 5362770      0t0     TCP localhost:8000->localhost:45456 (ESTABLISHED)
node    26484 kinow   23u     IPv4 5362772      0t0     TCP localhost:58418->localhost:48561 (ESTABLISHED)

Here's the output with two tabs opened:

$ lsof -p $(ps aux | grep "[c]onfigurable-http-proxy" | awk '{print $2}')
...
node    26484 kinow   20u     IPv6  507887      0t0     TCP *:8000 (LISTEN)
node    26484 kinow   21u     IPv4  507888      0t0     TCP localhost:8001 (LISTEN)
node    26484 kinow   22u     IPv6 5328558      0t0     TCP localhost:8000->localhost:44206 (ESTABLISHED)
node    26484 kinow   23u     IPv4 5328560      0t0     TCP localhost:57168->localhost:48561 (ESTABLISHED)
node    26484 kinow   24u     IPv6 5330280      0t0     TCP localhost:8000->localhost:44136 (ESTABLISHED)
node    26484 kinow   25u     IPv4 5330282      0t0     TCP localhost:57098->localhost:48561 (ESTABLISHED)

How to increase logging in JupyterHub / UI Server

Edit jupyterhub_config.py adding the following lines:

c.JupyterHub.log_level = 'DEBUG'
c.Spawner.debug = True
c.LocalProcessSpawner.debug = True
c.ConfigurableHTTPProxy.debug = True

This should increase the log levels. You can also start jupyterhub with jupyterhub --debug (redundant, however).

With extra logging, it is also possible to see the WebSocket connections in the log.

10:25:08.786 [ConfigProxy] debug: PROXY WEB /user/kinow/ to http://127.0.0.1:48561
10:25:10.158 [ConfigProxy] debug: PROXY WEB /user/kinow//userprofile to http://127.0.0.1:48561
10:25:10.405 [ConfigProxy] debug: PROXY WS /user/kinow/subscriptions to http://127.0.0.1:48561

Actually, the server is indeed shared by all handlers. But it acts as an event handler. The coroutine will be executed, then will start a while True loop, and for each message from the Queue it will execute a method that creates a connection context.

This connection context is the one responsible for holding the operations. So each connection can have multiple operations. But these are created within the context of a connection, not of the subscriptoin server lifecycle (another way to look at it, there is no self.operations = anywhere. Instead one method creates it, then pass it around to on_close(op_id, connection_context), or something like that.