search

hippware / rn-chat

MIT License
5 stars 0 forks source link

[Aborted discussion] Improvements to wocky-client test suite #2551

Closed bengtan closed 6 years ago

bengtan commented 6 years ago

@bernardd and @toland report that the client-side tests are brittle/flaky/unreliable.

It would be good to make them reliable/consistent (and capable of running concurrent tests against the same server)

bengtan commented 6 years ago

Let's turn this into a discussion (@bernardd, @toland, feel free to post your anecdotes), and we can spin out some smaller sub-tickets for action.

bernardd commented 6 years ago

Running current wocky-client master against the (fixed, apparently working, testing server):

yarn run v1.3.2
$ npm run build && npm run lint && npm run mocha --recursive ./test/*

> wocky-client@1.0.2 build /wocky-client
> tsc

> wocky-client@1.0.2 lint /wocky-client
> tslint -c tslint.json 'src/**/*.ts'

Warning: The 'no-unused-variable' rule requires type information.

> wocky-client@1.0.2 mocha /wocky-client
> mocha -r ts-node/register --require ./test/support/setup.js --timeout 30000 "./test/address.test.ts" "./test/bot.test.ts" "./test/event.test.ts" "./test/factory.test.ts" "./test/file.test.ts" "./test/geofence.test.ts" "./test/graphql.test.ts" "./test/img" "./test/profile.test.ts" "./test/reconnect.test.ts" "./test/support" "./test/xmpp.test.ts"

{"id":"123","loaded":true,"avatar":null,"handle":null,"firstName":"wow","lastName":null,"isBlocked":false,"isFollowed":false,"isFollower":false,"isNew":false,"followersSize":0,"followedSize":0,"botsSize":0,"roles":[]} null
  ✓ test
  Address
    ✓ location short
    ✓ bot address

  BotStore
[MST] /register
credentials 6118b4b4-83f5-11e8-a80b-0a580a0203f6 $T$qOkI9INJ5kznA+oI/bnjH+ue95uYLPQslNjiI/Hxrgs=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/setStatus
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 62ec0642-83f5-11e8-9268-0a580a020292 $T$i88GKUb8dawb4EUbKdDM41VMmo5DWciLBFPxkn0JGKs=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/setStatus
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /loadProfile
[MST] /requestRoster
[MST] /events/load
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/follow
[MST] /_subscribeToHomestream
[MST] /addRosterItem
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /profile/update
[MST] /profile/update
[MST] /createBot
    ✓ create bot (222ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/update
    ✓ update bot (251ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/shareToFollowers
    ✓ share bot
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/update
[MST] /_onNotification
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ update bot location (395ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/update
    ✓ update bot description (213ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/posts/load
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/createPost
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/posts/result/0/publish
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/createPost
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/posts/result/1/upload
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/posts/result/1/publish
    ✓ create bot posts (2739ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/posts/refresh
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/posts/load
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ list bots (395ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/upload
[MST] /files/get
[MST] /files/get
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/save
[MST] /files/get
[MST] /files/get
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
    ✓ upload cover image (14145ms)
[MST] /loadBot
    ✓ load bot (437ms)
[MST] /logout
[MST] /register
credentials 62ec0642-83f5-11e8-9268-0a580a020292 $T$tGzRu1Bi+4BMc7nCSGw3PFLqlES1UzAk4iA2GNnqibY=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/setStatus
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeBot
[MST] /requestRoster
[MST] /events/load
[MST] /loadBot
[MST] /addRosterItem
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeToHomestream
[MST] /_unsubscribeBot
[MST] /logout
[MST] /register
credentials 62ec0642-83f5-11e8-9268-0a580a020292 $T$B/On5lYvX8c1RI4Aglau+I3KPAqgGKljaWvhTq6TMnE=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/setStatus
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load subscribed bot with newly logged user2 (7510ms)
[MST] /createBot
[MST] /requestRoster
[MST] /events/load
    ✓ create bot2 (217ms)
[MST] /bots/storage/74e4da86-83f5-11e8-a70f-0a580a0203f6/update
[MST] /addRosterItem
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ update bot2 (249ms)
[MST] /geosearch
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onGeoBot
[MST] /bots/storage/74e4da86-83f5-11e8-a70f-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onGeoBot
[MST] /postProcessSnapshot
    ✓ geosearch (304ms)
[MST] /_subscribeToHomestream
    ✓ list own bots (498ms)
    ✓ list subscribed bots for user2 (379ms)
[MST] /_subscribeBot
    ✓ subscribe user2 for first bot (675ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/unsubscribe
    ✓ unsubscribe user2 for first bot (595ms)
[MST] /_subscribeBot
    ✓ subscribe again (220ms)
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/update
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ change first bot and verify updating for second user (895ms)
    1) change first bot description and expect new item update
[MST] /incorporateUpdates
    2) incorporate updates
[MST] /bots/storage/6535854a-83f5-11e8-9225-0a580a0203f6/subscribers/load
    ✓ get subscribers for bot (265ms)
[MST] /logout
[MST] /register
credentials 62ec0642-83f5-11e8-9268-0a580a020292 $T$/lRMJw9p4dN1/cL7c/JG8P0sgj7MTO1TA2NYvsl78Vg=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/setStatus
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /requestRoster
[MST] /events/load
[MST] /addRosterItem
[MST] /profiles/storage/6118b4b4-83f5-11e8-a80b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeToHomestream
    3) logout user2 and login again and verify HS
[MST] /disconnect
[MST] /removeBot
[MST] /login
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /geofenceBots/load
[MST] /loadChats
[MST] /profiles/get
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/setStatus
[MST] /profile/setStatus
[MST] /profiles/storage/62ec0642-83f5-11e8-9268-0a580a020292/postProcessSnapshot
[MST] /profile/postProcessSnapshot
[MST] /postProcessSnapshot
    4) disconnect user2 and login again and verify HS, delete items
[MST] /createBot
[MST] /requestRoster
[MST] /_loadUpdates
[MST] /bots/storage/8acd8c1c-83f5-11e8-b305-0a580a0203f6/update
[MST] /addRosterItem
[MST] /_subscribeToHomestream
[MST] /_onNotification
[MST] /bots/storage/8acd8c1c-83f5-11e8-b305-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
    5) check HS live notifications
    6) incorporate updates and check bot loading
[MST] /deleteBot
    ✓ delete bot and check updated HS
[MST] /removeBot
[MST] /removeBot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /remove
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /remove

  Home stream
{
  "id": "testmodel",
  "files": {
    "storage": {
      "123": {
        "id": "123"
      }
    }
  },
  "bots": {
    "storage": {
      "123": {
        "id": "123",
        "isSubscribed": false,
        "guest": false,
        "visitor": false,
        "title": "testBot",
        "server": null,
        "radius": 100,
        "geofence": false,
        "owner": "1",
        "image": null,
        "description": null,
        "visibility": 100,
        "location": null,
        "address": "",
        "followersSize": 0,
        "guestsSize": 0,
        "visitorsSize": 0,
        "totalItems": 0,
        "addressData": {
          "city": "",
          "country": "",
          "state": "",
          "county": ""
        },
        "visitors": {
          "result": [],
          "cursor": null,
          "count": null
        }
      }
    }
  },
  "profiles": {
    "storage": {
      "1": {
        "id": "1",
        "loaded": true,
        "avatar": "123",
        "handle": "test",
        "firstName": null,
        "lastName": null,
        "isBlocked": false,
        "isFollowed": false,
        "isFollower": false,
        "isNew": false,
        "followersSize": 0,
        "followedSize": 0,
        "botsSize": 0,
        "roles": []
      }
    }
  },
  "home": {
    "result": [
      {
        "id": "1",
        "time": 1531195126987,
        "bot": "123",
        "note": "Wow!"
      },
      {
        "id": "2",
        "time": 1531195126988,
        "bot": "123",
        "post": {
          "id": "1",
          "time": 1531195126988,
          "loaded": false,
          "content": "Really?",
          "title": "",
          "image": null,
          "profile": "1"
        }
      }
    ],
    "cursor": null,
    "count": null
  }
}
    ✓ model test
    ✓ model test2 (41ms)
    ✓ parse HS data
    ✓ parse live data

  FileStore
[MST] /register
credentials 8c31b448-83f5-11e8-a0a4-0a580a0203f6 $T$fWBmVs1DQOAN2vkjXPPCf7no44xE+XOnlUliKn1DbF4=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/8c31b448-83f5-11e8-a0a4-0a580a0203f6/setStatus
[MST] /profiles/storage/8c31b448-83f5-11e8-a0a4-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/upload
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
[MST] /files/get
[MST] /files/get
[MST] /profile/save
[MST] /loadProfile
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
    ✓ upload avatar (3422ms)
[MST] /logout
[MST] /register
credentials 8c31b448-83f5-11e8-a0a4-0a580a0203f6 $T$wMp29LLElMOfapuVvVLbZdHIgJ7axJbG+nM2PKNn8po=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/8c31b448-83f5-11e8-a0a4-0a580a0203f6/setStatus
[MST] /profiles/storage/8c31b448-83f5-11e8-a0a4-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
    ✓ logout, load profile and verify thumbnail (3189ms)
[MST] /files/get
[MST] /files/get
[MST] /_removeUpload
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
    ✓ remove upload (766ms)
[MST] /remove

  Geofence
[MST] /register
credentials 928d2ef8-83f5-11e8-9214-0a580a0203f6 $T$aoFPD3SrNO4E4AFM919ou61gtC0APqVPSFdJccNwKNQ=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/928d2ef8-83f5-11e8-9214-0a580a0203f6/setStatus
[MST] /profile/setStatus
[MST] /profiles/storage/928d2ef8-83f5-11e8-9214-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
credentials 928d2ef8-83f5-11e8-9214-0a580a0203f6 $T$aoFPD3SrNO4E4AFM919ou61gtC0APqVPSFdJccNwKNQ=
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 949f9cf8-83f5-11e8-8c56-0a580a0203f6 $T$+6+6L1GNsvQBVgp33dTWZ0vgGdXQnjglm9L6A15H3dU=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/949f9cf8-83f5-11e8-8c56-0a580a0203f6/setStatus
[MST] /profiles/storage/949f9cf8-83f5-11e8-8c56-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /setLocation
[MST] /requestRoster
[MST] /events/load
[MST] /setLocation
[MST] /setLocation
[MST] /setLocation
[MST] /profile/update
[MST] /_subscribeToHomestream
[MST] /profile/update
[MST] /loadProfile
[MST] /profiles/storage/928d2ef8-83f5-11e8-9214-0a580a0203f6/follow
[MST] /addRosterItem
[MST] /profiles/storage/949f9cf8-83f5-11e8-8c56-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/928d2ef8-83f5-11e8-9214-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /loadProfile
    ✓ load own profile, check hasUsedGeofence (236ms)
[MST] /createBot
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/update
    ✓ creates a geofence bot (495ms)
[MST] /loadProfile
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ load own profile, check hasUsedGeofence (218ms)
[MST] /createBot
[MST] /_onNotification
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /bots/storage/97a70940-83f5-11e8-bf09-0a580a020292/update
    ✓ creates a geofence bot2 (481ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/visitors/load
[MST] /setLocation
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /bots/storage/97a70940-83f5-11e8-bf09-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /setLocation
[MST] /_onBotVisitor
[MST] /profiles/storage/928d2ef8-83f5-11e8-9214-0a580a0203f6/postProcessSnapshot
[MST] /bots/storage/97a70940-83f5-11e8-bf09-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load visitors and live updates (847ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/visitors/refresh
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/visitors/load
[MST] /setLocation
[MST] /setLocation
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/97a70940-83f5-11e8-bf09-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load visitors2 (829ms)
[MST] /loadBot
    ✓ loads own bot (437ms)
[MST] /loadBot
    ✓ loads bot (438ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/subscribeGeofence
    ✓ geofence subscribes (219ms)
[MST] /loadBot
    ✓ loads bot again (449ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/guests/load
    ✓ load bot guests (252ms)
[MST] /setLocation
[MST] /setLocation
[MST] /setLocation
[MST] /setLocation
[MST] /_onBotVisitor
[MST] /bots/storage/97a70940-83f5-11e8-bf09-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ user2 enters the bot and verify activeBots (804ms)
[MST] /geofenceBots/refresh
[MST] /geofenceBots/load
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /profiles/storage/949f9cf8-83f5-11e8-8c56-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ verify activeBots after refresh (515ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/unsubscribeGeofence
    ✓ geofence unsubscribe (221ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/guests/refresh
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/guests/load
[MST] /_onBotVisitor
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load bot guests again (225ms)
[MST] /loadBot
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/unsubscribeGeofence
    ✓ geofence unsubscribe owner (672ms)
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/guests/refresh
[MST] /bots/storage/973a3824-83f5-11e8-83b4-0a580a020292/guests/load
    ✓ load bot guests again 2 (215ms)
[MST] /removeBot
[MST] /removeBot
[MST] /remove
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /remove
after done

  GraphQL
[MST] /register
credentials 9c6ebd60-83f5-11e8-ab74-0a580a0203f6 $T$uZs1faWM4PsI8SIJgDYewOam8FRS8PZoVUUm9Up1Pvg=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/9c6ebd60-83f5-11e8-ab74-0a580a0203f6/setStatus
[MST] /profiles/storage/9c6ebd60-83f5-11e8-ab74-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 9e4dfeac-83f5-11e8-b450-0a580a0203f6 $T$ZX86HBxF7BQgho6kgLoJ9gZ8pVV9CGZZLkWYzcylEoQ=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/9e4dfeac-83f5-11e8-b450-0a580a0203f6/setStatus
[MST] /profiles/storage/9e4dfeac-83f5-11e8-b450-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
    ✓ get credentials via XMPP (8170ms)
    ✓ loads profile (223ms)
    ✓ loads other profile (215ms)
[MST] /createBot
[MST] /bots/storage/a13bc98c-83f5-11e8-8eea-0a580a020292/update
[MST] /createBot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/a186c2fc-83f5-11e8-8a57-0a580a020292/update
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ gets some bots (1845ms)
[MST] /_onBotVisitor
[MST] /bots/storage/a13bc98c-83f5-11e8-8eea-0a580a020292/postProcessSnapshot
[MST] /profiles/storage/9c6ebd60-83f5-11e8-ab74-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check subscription arrive (582ms)
[MST] /_onBotVisitor
[MST] /bots/storage/a13bc98c-83f5-11e8-8eea-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check subscription exit (639ms)
    ✓ load bot (413ms)
[MST] /remove
[MST] /remove

  ProfileStore
[MST] /register
credentials a3e963e2-83f5-11e8-9367-0a580a020292 $T$oZNPv+QO2RIK86RXLiYR8kxQERGzbX61OEfhDfPxPlU=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/a3e963e2-83f5-11e8-9367-0a580a020292/setStatus
[MST] /profiles/storage/a3e963e2-83f5-11e8-9367-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
    ✓ create first user (3515ms)
[MST] /register
[MST] /_subscribeToHomestream
credentials a5fe3b3a-83f5-11e8-bc1e-0a580a020292 $T$2kkDtsGc+p0hxFMYq5hemcDOMWUt9N7ZAixIlUfRBP0=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/a5fe3b3a-83f5-11e8-bc1e-0a580a020292/setStatus
[MST] /profiles/storage/a5fe3b3a-83f5-11e8-bc1e-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
    ✓ create second user (3565ms)
[MST] /register
[MST] /_subscribeToHomestream
credentials a8240980-83f5-11e8-b65b-0a580a0203f6 $T$sGftTQGw7JIXZ9Vlp889uDnVEnwGQ7F6Q5o34k4zPM0=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/a8240980-83f5-11e8-b65b-0a580a0203f6/setStatus
[MST] /profiles/storage/a8240980-83f5-11e8-b65b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
    ✓ create third user (3376ms)
[MST] /loadProfile
[MST] /_subscribeToHomestream
[MST] /profiles/storage/a5fe3b3a-83f5-11e8-bc1e-0a580a020292/follow
[MST] /addRosterItem
[MST] /profiles/storage/a3e963e2-83f5-11e8-9367-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/a5fe3b3a-83f5-11e8-bc1e-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /loadProfile
[MST] /profiles/storage/a8240980-83f5-11e8-b65b-0a580a0203f6/follow
[MST] /addRosterItem
[MST] /profiles/storage/a3e963e2-83f5-11e8-9367-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/a8240980-83f5-11e8-b65b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
    ✓ add two users to roster (1368ms)
    ✓ wait profile
[MST] /profiles/get
[MST] /profiles/get
[MST] /profiles/get
[MST] /profiles/get
    ✓ get profile and check isOwn
[MST] /loadProfile
    ✓ followed profile relations (456ms)
    ✓ followers profile relations (218ms)
[MST] /lookup
    ✓ test lookup (215ms)
[MST] /loadProfile
    ✓ profile details (220ms)
[MST] /remove
[MST] /remove
[MST] /remove

  GraphQL
AUTHENTICATED:  false
AUTHENTICATED:  false
AUTHENTICATED:  false
    ✓ test connection (3416ms)

  ConnectStore
[MST] /register
credentials ae09af44-83f5-11e8-8107-0a580a020292 $T$YP6zC4cucPybK091VwsAs6jdkuf1T3VA7hNi/VAVx40=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/setStatus
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials affbefce-83f5-11e8-bd39-0a580a020292 $T$RSIGxKipTarXrXgoscn8DRYBAoHgkc+sA9Sca5Jeh1s=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check automatic loading profile
    ✓ check automatic loading profile2
[MST] /profile/update
    ✓ update profile with invalid handle (201ms)
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
[MST] /profile/update
[MST] /_subscribeToHomestream
[MST] /profile/update
    ✓ update profile (818ms)
[MST] /loadProfile
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/follow
[MST] /addRosterItem
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /loadProfile
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/follow
[MST] /addRosterItem
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/get
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/setStatus
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ make them friends (1391ms)
[MST] /createChat
[MST] /chats/_list/0/message/setBody
[MST] /chats/_list/0/message/send
[MST] /chats/_list/0/message/setBody
[MST] /chats/_list/0/message/send
[MST] /_addMessage
[MST] /postProcessSnapshot
[MST] /_addMessage
[MST] /postProcessSnapshot
    ✓ send message (446ms)
[MST] /createChat
[MST] /chats/_list/0/message/upload
[MST] /chats/_list/0/message/send
[MST] /_addMessage
[MST] /files/storage/tros:ae09af44-83f5-11e8-8107-0a580a020292@testing.dev.tinyrobot.com~0file~0b33ce2ce-83f5-11e8-a7d3-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
    ✓ send media (2733ms)
[MST] /disconnect
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
    ✓ check profile status (229ms)
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /login
[MST] /geofenceBots/load
[MST] /loadChats
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/setStatus
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profile/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /profile/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check roster (1900ms)
    ✓ check message receive
[MST] /logout
[MST] /requestRoster
[MST] /_loadUpdates
[MST] /register
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
credentials affbefce-83f5-11e8-bd39-0a580a020292 $T$htubWv8SHZoYtb85jxgo1+81FovvAFLvOAE5Ybr3z2A=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/setStatus
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/setStatus
[MST] /profiles/storage/affbefce-83f5-11e8-bd39-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /requestRoster
[MST] /events/load
[MST] /addRosterItem
[MST] /profiles/storage/ae09af44-83f5-11e8-8107-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
[MST] /chats/_list/0/load
[MST] /_subscribeToHomestream
[MST] /_addMessage
[MST] /postProcessSnapshot
[MST] /_addMessage
[MST] /postProcessSnapshot
[MST] /_addMessage
    ✓ check conversations (4234ms)
[MST] /remove
[MST] /remove

  77 passing (2m)
  6 failing

  1) BotStore change first bot description and expect new item update:

      AssertionError: expected 0 to equal 1
      + expected - actual

      -0
      +1

      at Object.<anonymous> (test/bot.test.ts:290:42)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/bot.test.ts:288:78)

  2) BotStore incorporate updates:

      AssertionError: expected 2 to equal 3
      + expected - actual

      -2
      +3

      at Object.<anonymous> (test/bot.test.ts:303:41)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/bot.test.ts:299:42)

  3) BotStore logout user2 and login again and verify HS:
     Error: timeout of 30000ms exceeded. Ensure the done() callback is being called in this test.

  4) BotStore disconnect user2 and login again and verify HS, delete items:

      AssertionError: expected 2 to equal 3
      + expected - actual

      -2
      +3

      at Object.<anonymous> (test/bot.test.ts:339:46)
      at Generator.next (<anonymous>)
      at fulfilled (node_modules/tslib/tslib.js:104:62)
      at tryCallOne (node_modules/promise/lib/core.js:37:12)
      at node_modules/promise/lib/core.js:123:15
      at flush (node_modules/asap/raw.js:50:29)
      at _combinedTickCallback (internal/process/next_tick.js:131:7)
      at process._tickCallback (internal/process/next_tick.js:180:9)

  5) BotStore check HS live notifications:
     TypeError: Cannot read property 'id' of null
      at Object.<anonymous> (test/bot.test.ts:352:30)
      at Generator.next (<anonymous>)
      at fulfilled (node_modules/tslib/tslib.js:104:62)
      at tryCallOne (node_modules/promise/lib/core.js:37:12)
      at node_modules/promise/lib/core.js:123:15
      at flush (node_modules/asap/raw.js:50:29)
      at _combinedTickCallback (internal/process/next_tick.js:131:7)
      at process._tickCallback (internal/process/next_tick.js:180:9)

  6) BotStore incorporate updates and check bot loading:

      AssertionError: expected 2 to equal 3
      + expected - actual

      -2
      +3

      at Object.<anonymous> (test/bot.test.ts:367:46)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/bot.test.ts:365:64)

npm ERR! code ELIFECYCLE
npm ERR! errno 6
npm ERR! wocky-client@1.0.2 mocha: `mocha -r ts-node/register --require ./test/support/setup.js --timeout 30000 "./test/address.test.ts" "./test/bot.test.ts" "./test/event.test.ts" "./test/factory.test.ts" "./test/file.test.ts" "./test/geofence.test.ts" "./test/graphql.test.ts" "./test/img" "./test/profile.test.ts" "./test/reconnect.test.ts" "./test/support" "./test/xmpp.test.ts"`
npm ERR! Exit status 6
npm ERR! 
npm ERR! Failed at the wocky-client@1.0.2 mocha script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /root/.npm/_logs/2018-07-10T04_00_02_620Z-debug.log
error Command failed with exit code 6.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
bernardd commented 6 years ago

Running master against testing the other night when I was trying to reproduce the reported issue: (Yes, this one's been fixed, but why did a clean checkout from master fail this way in the first place?)

yarn run v1.5.1
$ npm run lint && npm run tsc && npm run mocha && npm run jest:all

> tinyrobot@3.1.0 lint /wocky-client
> tslint -p . -c tslint.json  'src/**/*.tsx'

> tinyrobot@3.1.0 tsc /wocky-client
> node node_modules/.bin/tsc

src/store/HomeStore.ts(27,28): error TS2345: Argument of type 'IModelType<{ id?: any; } & {} & { id?: any; isSubscribed?: any; guest?: any; visitor?: any; title...' is not assignable to parameter of type 'IType<any, { id: string; } & { readonly service: any; } & { uploading: boolean; uploaded: boolean...'.
  Types of property 'validate' are incompatible.
    Type '(thing: any, context: IContextEntry[]) => IValidationError[]' is not assignable to type '(thing: any, context: IContextEntry[]) => IValidationError[]'. Two different types with this name exist, but they are unrelated.
      Types of parameters 'context' and 'context' are incompatible.
        Type 'IContextEntry[]' is not assignable to type 'IContextEntry[]'. Two different types with this name exist, but they are unrelated.
src/store/HomeStore.ts(60,25): error TS2345: Argument of type 'IModelType<{ latitude?: any; longitude?: any; accuracy?: any; }, { latitude: number; longitude: n...' is not assignable to parameter of type 'IType<{ latitude?: any; longitude?: any; accuracy?: any; }, { latitude: number; longitude: number...'.
src/store/HomeStore.ts(61,48): error TS2345: Argument of type 'IModelType<{ id?: any; } & {} & { id?: any; isSubscribed?: any; guest?: any; visitor?: any; title...' is not assignable to parameter of type 'IType<any, { id: string; } & { readonly service: any; } & { uploading: boolean; uploaded: boolean...'.
src/store/LocationStore.ts(59,27): error TS2345: Argument of type 'IModelType<{ latitude?: any; longitude?: any; accuracy?: any; }, { latitude: number; longitude: n...' is not assignable to parameter of type 'IType<{ latitude?: any; longitude?: any; accuracy?: any; }, { latitude: number; longitude: number...'.
  Types of property 'validate' are incompatible.
    Type '(thing: any, context: IContextEntry[]) => IValidationError[]' is not assignable to type '(thing: any, context: IContextEntry[]) => IValidationError[]'. Two different types with this name exist, but they are unrelated.
      Types of parameters 'context' and 'context' are incompatible.
        Type 'IContextEntry[]' is not assignable to type 'IContextEntry[]'. Two different types with this name exist, but they are unrelated.
          Type 'IContextEntry' is not assignable to type 'IContextEntry'. Two different types with this name exist, but they are unrelated.
            Types of property 'type' are incompatible.
              Type 'IType<any, any>' is not assignable to type 'IType<any, any>'. Two different types with this name exist, but they are unrelated.
                Types of property 'validate' are incompatible.
                  Type '(thing: any, context: IContextEntry[]) => IValidationError[]' is not assignable to type '(thing: any, context: IContextEntry[]) => IValidationError[]'. Two different types with this name exist, but they are unrelated.
                    Types of parameters 'context' and 'context' are incompatible.
                      Type 'IContextEntry[]' is not assignable to type 'IContextEntry[]'. Two different types with this name exist, but they are unrelated.
                        Type 'IContextEntry' is not assignable to type 'IContextEntry'. Two different types with this name exist, but they are unrelated.
                          Types of property 'type' are incompatible.
                            Type 'IType<any, any>' is not assignable to type 'IType<any, any>'. Two different types with this name exist, but they are unrelated.
                              Types of property 'validate' are incompatible.
                                Type '(thing: any, context: IContextEntry[]) => IValidationError[]' is not assignable to type '(thing: any, context: IContextEntry[]) => IValidationError[]'. Two different types with this name exist, but they are unrelated.
                                  Types of parameters 'context' and 'context' are incompatible.
                                    Type 'IContextEntry[]' is not assignable to type 'IContextEntry[]'. Two different types with this name exist, but they are unrelated.
src/store/PersistableModel.ts(5,28): error TS2345: Argument of type '{ id: string; wocky: IModelType<{ id?: any; } & { files?: any; bots?: any; profiles?: any; } & { ...' is not assignable to parameter of type 'IModelProperties<{ id: string; wocky: { id: any; } & { readonly service: any; } & { files: any; b...'.
  Types of property 'wocky' are incompatible.
    Type 'IModelType<{ id?: any; } & { files?: any; bots?: any; profiles?: any; } & { id?: any; username?: ...' is not assignable to type '({ id: string; } & { readonly service: any; } & { files: { storage: any; } & { readonly snapshot:...'.
      Type 'IModelType<{ id?: any; } & { files?: any; bots?: any; profiles?: any; } & { id?: any; username?: ...' is not assignable to type 'IType<any, { id: string; } & { readonly service: any; } & { files: { storage: any; } & { readonly...'.
        Types of property 'validate' are incompatible.
          Type '(thing: any, context: IContextEntry[]) => IValidationError[]' is not assignable to type '(thing: any, context: IContextEntry[]) => IValidationError[]'. Two different types with this name exist, but they are unrelated.
            Types of parameters 'context' and 'context' are incompatible.
              Type 'IContextEntry[]' is not assignable to type 'IContextEntry[]'. Two different types with this name exist, but they are unrelated.
src/store/SelectableProfileList.ts(5,28): error TS2345: Argument of type 'IModelType<{ id?: any; } & { loaded?: any; } & { id?: any; avatar?: any; handle?: any; status?: a...' is not assignable to parameter of type 'IType<any, { id: string; } & { readonly service: any; } & { loaded: boolean; } & { load: (data: a...'.
  Types of property 'validate' are incompatible.
    Type '(thing: any, context: IContextEntry[]) => IValidationError[]' is not assignable to type '(thing: any, context: IContextEntry[]) => IValidationError[]'. Two different types with this name exist, but they are unrelated.
      Types of parameters 'context' and 'context' are incompatible.
        Type 'IContextEntry[]' is not assignable to type 'IContextEntry[]'. Two different types with this name exist, but they are unrelated.
src/store/index.ts(65,19): error TS2345: Argument of type '{ wocky: IModelType<{ id?: any; } & { files?: any; bots?: any; profiles?: any; } & { id?: any; us...' is not assignable to parameter of type 'IModelProperties<{ wocky: { id: any; } & { readonly service: any; } & { files: any; bots: any; pr...'.
  Types of property 'wocky' are incompatible.
    Type 'IModelType<{ id?: any; } & { files?: any; bots?: any; profiles?: any; } & { id?: any; username?: ...' is not assignable to type '({ id: string; } & { readonly service: any; } & { files: { storage: any; } & { readonly snapshot:...'.
      Type 'IModelType<{ id?: any; } & { files?: any; bots?: any; profiles?: any; } & { id?: any; username?: ...' is not assignable to type 'IType<any, { id: string; } & { readonly service: any; } & { files: { storage: any; } & { readonly...'.
src/store/index.ts(122,49): error TS2339: Property 'wocky' does not exist on type 'IStateTreeNode & { toJSON?(): {}; } & ISnapshottable<{}>'.
src/store/index.ts(123,65): error TS2339: Property 'wocky' does not exist on type 'IStateTreeNode & { toJSON?(): {}; } & ISnapshottable<{}>'.
third-party/wocky-client/src/store/Factory.ts(12,54): error TS2314: Generic type 'ObservableMap<V>' requires 1 type argument(s).
third-party/wocky-client/src/store/Wocky.ts(76,73): error TS2314: Generic type 'ObservableMap<V>' requires 1 type argument(s).
third-party/wocky-client/src/store/Wocky.ts(81,70): error TS2314: Generic type 'ObservableMap<V>' requires 1 type argument(s).
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! tinyrobot@3.1.0 tsc: `node node_modules/.bin/tsc`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the tinyrobot@3.1.0 tsc script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /root/.npm/_logs/2018-07-06T07_09_24_129Z-debug.log
error An unexpected error occurred: "Command failed.
Exit code: 1
Command: sh
Arguments: -c npm run lint && npm run tsc && npm run mocha && npm run jest:all
Directory: /wocky-client
Output:
".
info If you think this is a bug, please open a bug report with the information provided in "/wocky-client/yarn-error.log".
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
bernardd commented 6 years ago

Just for completeness, I also pinned yarn and npm to exactly the versions Eric gave us (1.7.0 and 5.8.0 respectively). That reduced the failures by 1:

yarn run v1.7.0
$ npm run build && npm run lint && npm run mocha --recursive ./test/*

> wocky-client@1.0.2 build /wocky-client
> tsc

> wocky-client@1.0.2 lint /wocky-client
> tslint -c tslint.json 'src/**/*.ts'

Warning: The 'no-unused-variable' rule requires type information.

> wocky-client@1.0.2 mocha /wocky-client
> mocha -r ts-node/register --require ./test/support/setup.js --timeout 30000 "./test/address.test.ts" "./test/bot.test.ts" "./test/event.test.ts" "./test/factory.test.ts" "./test/file.test.ts" "./test/geofence.test.ts" "./test/graphql.test.ts" "./test/img" "./test/profile.test.ts" "./test/reconnect.test.ts" "./test/support" "./test/xmpp.test.ts"

{"id":"123","loaded":true,"avatar":null,"handle":null,"firstName":"wow","lastName":null,"isBlocked":false,"isFollowed":false,"isFollower":false,"isNew":false,"followersSize":0,"followedSize":0,"botsSize":0,"roles":[]} null
  ✓ test
  Address
    ✓ location short
    ✓ bot address

  BotStore
[MST] /register
credentials 23e4038c-83fa-11e8-86a3-0a580a020292 $T$eJt9+evyEz2EECGDyg4DoVo5erFwerWYIPxGivSKfoY=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/setStatus
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 25b765e6-83fa-11e8-af48-0a580a020292 $T$KUUUrCxZw8l9liHrAOWXaYmcnRfHletgiltcx3Wnm8I=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/setStatus
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /loadProfile
[MST] /requestRoster
[MST] /events/load
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/follow
[MST] /_subscribeToHomestream
[MST] /addRosterItem
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /profile/update
[MST] /profile/update
[MST] /createBot
    ✓ create bot (220ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/update
    ✓ update bot (254ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/shareToFollowers
    ✓ share bot
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/update
[MST] /_onNotification
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ update bot location (386ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/update
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ update bot description (222ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/posts/load
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/createPost
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/posts/result/0/publish
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/createPost
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/posts/result/1/upload
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/posts/result/1/publish
    ✓ create bot posts (1964ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/posts/refresh
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/posts/load
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ list bots (386ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/upload
[MST] /files/get
[MST] /files/get
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/save
[MST] /files/get
[MST] /files/get
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
    ✓ upload cover image (3137ms)
[MST] /loadBot
    ✓ load bot (457ms)
[MST] /logout
[MST] /register
credentials 25b765e6-83fa-11e8-af48-0a580a020292 $T$LPEodaQAUBV6gGqFcAM/RXBMMoQqTRK4cOreP8qXXWw=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/setStatus
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeBot
[MST] /requestRoster
[MST] /events/load
[MST] /loadBot
[MST] /addRosterItem
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeToHomestream
[MST] /_unsubscribeBot
[MST] /logout
[MST] /register
credentials 25b765e6-83fa-11e8-af48-0a580a020292 $T$K3j9SRxBW721Qz9mgykAdgKz/YOhEVfYUVZ9779/ogU=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/setStatus
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load subscribed bot with newly logged user2 (7711ms)
[MST] /createBot
[MST] /requestRoster
[MST] /events/load
    ✓ create bot2 (221ms)
[MST] /bots/storage/30c5a66e-83fa-11e8-9e73-0a580a020292/update
[MST] /addRosterItem
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ update bot2 (258ms)
[MST] /geosearch
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onGeoBot
[MST] /bots/storage/30c5a66e-83fa-11e8-9e73-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeToHomestream
[MST] /_onGeoBot
[MST] /postProcessSnapshot
    ✓ geosearch (307ms)
    ✓ list own bots (484ms)
    ✓ list subscribed bots for user2 (395ms)
[MST] /_subscribeBot
    ✓ subscribe user2 for first bot (808ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/unsubscribe
    ✓ unsubscribe user2 for first bot (635ms)
[MST] /_subscribeBot
    ✓ subscribe again (227ms)
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/update
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ change first bot and verify updating for second user (854ms)
    1) change first bot description and expect new item update
[MST] /incorporateUpdates
    2) incorporate updates
[MST] /bots/storage/27fb9f5c-83fa-11e8-9115-0a580a020292/subscribers/load
    ✓ get subscribers for bot (294ms)
[MST] /logout
[MST] /register
credentials 25b765e6-83fa-11e8-af48-0a580a020292 $T$CRYxoRUrfa7lSJg7sACP+mHUwE5MPNjTCvaLRIbwJTU=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/setStatus
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /requestRoster
[MST] /events/load
[MST] /addRosterItem
[MST] /profiles/storage/23e4038c-83fa-11e8-86a3-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_subscribeToHomestream
    3) logout user2 and login again and verify HS
[MST] /disconnect
[MST] /removeBot
[MST] /login
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /profiles/get
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/setStatus
[MST] /profile/setStatus
[MST] /profiles/storage/25b765e6-83fa-11e8-af48-0a580a020292/postProcessSnapshot
[MST] /profile/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /geofenceBots/load
[MST] /loadChats
[MST] /requestRoster
[MST] /_loadUpdates
    4) disconnect user2 and login again and verify HS, delete items
[MST] /createBot
[MST] /addRosterItem
[MST] /bots/storage/471609cc-83fa-11e8-b932-0a580a020292/update
[MST] /_subscribeToHomestream
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /bots/storage/471609cc-83fa-11e8-b932-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /bots/storage/471609cc-83fa-11e8-b932-0a580a020292/setPublic
[MST] /bots/storage/471609cc-83fa-11e8-b932-0a580a020292/save
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/471609cc-83fa-11e8-b932-0a580a020292/shareToFollowers
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ check HS live notifications (1777ms)
    5) incorporate updates and check bot loading
[MST] /deleteBot
    ✓ delete bot and check updated HS
[MST] /removeBot
[MST] /removeBot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /remove
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /remove

  Home stream
{
  "id": "testmodel",
  "files": {
    "storage": {
      "123": {
        "id": "123"
      }
    }
  },
  "bots": {
    "storage": {
      "123": {
        "id": "123",
        "isSubscribed": false,
        "guest": false,
        "visitor": false,
        "title": "testBot",
        "server": null,
        "radius": 100,
        "geofence": false,
        "owner": "1",
        "image": null,
        "description": null,
        "visibility": 100,
        "location": null,
        "address": "",
        "followersSize": 0,
        "guestsSize": 0,
        "visitorsSize": 0,
        "totalItems": 0,
        "addressData": {
          "city": "",
          "country": "",
          "state": "",
          "county": ""
        },
        "visitors": {
          "result": [],
          "cursor": null,
          "count": null
        }
      }
    }
  },
  "profiles": {
    "storage": {
      "1": {
        "id": "1",
        "loaded": true,
        "avatar": "123",
        "handle": "test",
        "firstName": null,
        "lastName": null,
        "isBlocked": false,
        "isFollowed": false,
        "isFollower": false,
        "isNew": false,
        "followersSize": 0,
        "followedSize": 0,
        "botsSize": 0,
        "roles": []
      }
    }
  },
  "home": {
    "result": [
      {
        "id": "1",
        "time": 1531197161829,
        "bot": "123",
        "note": "Wow!"
      },
      {
        "id": "2",
        "time": 1531197161830,
        "bot": "123",
        "post": {
          "id": "1",
          "time": 1531197161830,
          "loaded": false,
          "content": "Really?",
          "title": "",
          "image": null,
          "profile": "1"
        }
      }
    ],
    "cursor": null,
    "count": null
  }
}
    ✓ model test
    ✓ model test2
    ✓ parse HS data
    ✓ parse live data

  FileStore
[MST] /register
credentials 490bf94e-83fa-11e8-a7d5-0a580a0203f6 $T$gSqtVTgJeSvaXlsuEQb+Quf8PuTTK5K8QPQ89SCB//w=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/490bf94e-83fa-11e8-a7d5-0a580a0203f6/setStatus
[MST] /profiles/storage/490bf94e-83fa-11e8-a7d5-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/upload
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
[MST] /files/get
[MST] /files/get
[MST] /profile/save
[MST] /loadProfile
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
    ✓ upload avatar (2574ms)
[MST] /logout
[MST] /register
credentials 490bf94e-83fa-11e8-a7d5-0a580a0203f6 $T$AXiMCFITzwgpcxBHOLuD0T3h/75SND3FM8StL1K7rz4=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/490bf94e-83fa-11e8-a7d5-0a580a0203f6/setStatus
[MST] /profiles/storage/490bf94e-83fa-11e8-a7d5-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
    ✓ logout, load profile and verify thumbnail (3141ms)
[MST] /files/get
[MST] /files/get
[MST] /_removeUpload
[MST] /requestRoster
[MST] /events/load
    ✓ remove upload (497ms)
[MST] /remove
[MST] /_subscribeToHomestream

  Geofence
[MST] /register
credentials 4eb228dc-83fa-11e8-968d-0a580a0203f6 $T$OdXOz7mTDivshj3sPSmNCuy/MgjqwiYF414AW/suMcs=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/4eb228dc-83fa-11e8-968d-0a580a0203f6/setStatus
[MST] /profiles/storage/4eb228dc-83fa-11e8-968d-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
credentials 4eb228dc-83fa-11e8-968d-0a580a0203f6 $T$OdXOz7mTDivshj3sPSmNCuy/MgjqwiYF414AW/suMcs=
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 506a6978-83fa-11e8-bae0-0a580a0203f6 $T$6WJ+fE5bSxOsSFxDNEOp8et0JzIri6RgPO8zAC9l4fo=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/506a6978-83fa-11e8-bae0-0a580a0203f6/setStatus
[MST] /profiles/storage/506a6978-83fa-11e8-bae0-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /setLocation
[MST] /requestRoster
[MST] /events/load
[MST] /setLocation
[MST] /setLocation
[MST] /_subscribeToHomestream
[MST] /setLocation
[MST] /profile/update
[MST] /profile/update
[MST] /loadProfile
[MST] /profiles/storage/4eb228dc-83fa-11e8-968d-0a580a0203f6/follow
[MST] /addRosterItem
[MST] /profiles/storage/506a6978-83fa-11e8-bae0-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/4eb228dc-83fa-11e8-968d-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /loadProfile
    ✓ load own profile, check hasUsedGeofence (238ms)
[MST] /createBot
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/update
    ✓ creates a geofence bot (483ms)
[MST] /loadProfile
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load own profile, check hasUsedGeofence (231ms)
[MST] /createBot
[MST] /bots/storage/5399cabc-83fa-11e8-8e1f-0a580a0203f6/update
    ✓ creates a geofence bot2 (486ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/visitors/load
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /bots/storage/5399cabc-83fa-11e8-8e1f-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /setLocation
[MST] /setLocation
[MST] /_onBotVisitor
[MST] /bots/storage/5399cabc-83fa-11e8-8e1f-0a580a0203f6/postProcessSnapshot
[MST] /profiles/storage/4eb228dc-83fa-11e8-968d-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load visitors and live updates (932ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/visitors/refresh
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/visitors/load
[MST] /setLocation
[MST] /setLocation
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/5399cabc-83fa-11e8-8e1f-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load visitors2 (875ms)
[MST] /loadBot
    ✓ loads own bot (463ms)
[MST] /loadBot
    ✓ loads bot (431ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/subscribeGeofence
    ✓ geofence subscribes (221ms)
[MST] /loadBot
    ✓ loads bot again (445ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/guests/load
    ✓ load bot guests (252ms)
[MST] /setLocation
[MST] /setLocation
[MST] /setLocation
[MST] /setLocation
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/5399cabc-83fa-11e8-8e1f-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ user2 enters the bot and verify activeBots (793ms)
[MST] /geofenceBots/refresh
[MST] /geofenceBots/load
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /profiles/storage/506a6978-83fa-11e8-bae0-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ verify activeBots after refresh (570ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/unsubscribeGeofence
    ✓ geofence unsubscribe (228ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/guests/refresh
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/guests/load
[MST] /_onBotVisitor
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load bot guests again (232ms)
[MST] /loadBot
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/unsubscribeGeofence
    ✓ geofence unsubscribe owner (655ms)
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/guests/refresh
[MST] /bots/storage/5322b1d4-83fa-11e8-9de9-0a580a0203f6/guests/load
    ✓ load bot guests again 2 (226ms)
[MST] /removeBot
[MST] /removeBot
[MST] /remove
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /remove
after done

  GraphQL
[MST] /register
credentials 587f0e2a-83fa-11e8-827f-0a580a0203f6 $T$T/FouUYACW/DnhWg2tJGADSWEbd2wGLybWqmKhLIgfA=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/587f0e2a-83fa-11e8-827f-0a580a0203f6/setStatus
[MST] /profiles/storage/587f0e2a-83fa-11e8-827f-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 5a4efbb6-83fa-11e8-9f1b-0a580a020292 $T$uDswUuvNf8Xbfhv1VDoP7Zz+vbEmt8hssEZPnKpze5k=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/5a4efbb6-83fa-11e8-9f1b-0a580a020292/setStatus
[MST] /profiles/storage/5a4efbb6-83fa-11e8-9f1b-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
    ✓ get credentials via XMPP (8248ms)
    ✓ loads profile (219ms)
    ✓ loads other profile (219ms)
[MST] /createBot
[MST] /bots/storage/5d54872c-83fa-11e8-9e16-0a580a0203f6/update
[MST] /createBot
[MST] /_onNotification
[MST] /postProcessSnapshot
[MST] /bots/storage/5d9a3ccc-83fa-11e8-b729-0a580a0203f6/update
[MST] /_onNotification
[MST] /postProcessSnapshot
    ✓ gets some bots (1806ms)
    ✓ check subscription arrive (550ms)
[MST] /_onBotVisitor
[MST] /bots/storage/5d54872c-83fa-11e8-9e16-0a580a0203f6/postProcessSnapshot
[MST] /profiles/storage/587f0e2a-83fa-11e8-827f-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check subscription exit (551ms)
[MST] /_onBotVisitor
[MST] /bots/storage/5d54872c-83fa-11e8-9e16-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ load bot (437ms)
[MST] /remove
[MST] /remove

  ProfileStore
[MST] /register
credentials 5fe8fcc0-83fa-11e8-9ebc-0a580a0203f6 $T$BYQZFeQgReqcUaZtjqCftFosfKTzk5FHxAvXoqXDtZ0=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/5fe8fcc0-83fa-11e8-9ebc-0a580a0203f6/setStatus
[MST] /profiles/storage/5fe8fcc0-83fa-11e8-9ebc-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
    ✓ create first user (3565ms)
[MST] /register
[MST] /_subscribeToHomestream
credentials 620dff50-83fa-11e8-bf0b-0a580a0203f6 $T$oR4DVKvMkHI0TvRO6jmoQ5+2DQVSQgL+YuHg7qPbUz4=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/620dff50-83fa-11e8-bf0b-0a580a0203f6/setStatus
[MST] /profiles/storage/620dff50-83fa-11e8-bf0b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
    ✓ create second user (3492ms)
[MST] /register
[MST] /_subscribeToHomestream
credentials 64234610-83fa-11e8-83d1-0a580a0203f6 $T$bMgJkiBir7CPIePPLLtTD+/TQa06fM5dSbMwI1RkNY0=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/64234610-83fa-11e8-83d1-0a580a0203f6/setStatus
[MST] /profiles/storage/64234610-83fa-11e8-83d1-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
    ✓ create third user (3576ms)
[MST] /loadProfile
[MST] /_subscribeToHomestream
[MST] /profiles/storage/620dff50-83fa-11e8-bf0b-0a580a0203f6/follow
[MST] /addRosterItem
[MST] /profiles/storage/5fe8fcc0-83fa-11e8-9ebc-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/620dff50-83fa-11e8-bf0b-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /loadProfile
[MST] /profiles/storage/64234610-83fa-11e8-83d1-0a580a0203f6/follow
[MST] /addRosterItem
[MST] /profiles/storage/5fe8fcc0-83fa-11e8-9ebc-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/64234610-83fa-11e8-83d1-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
    ✓ add two users to roster (1387ms)
    ✓ wait profile
[MST] /profiles/get
[MST] /profiles/get
[MST] /profiles/get
[MST] /profiles/get
    ✓ get profile and check isOwn
[MST] /loadProfile
    ✓ followed profile relations (482ms)
    ✓ followers profile relations (219ms)
[MST] /lookup
    ✓ test lookup (209ms)
[MST] /loadProfile
    ✓ profile details (222ms)
[MST] /remove
[MST] /remove
[MST] /remove

  GraphQL
AUTHENTICATED:  false
AUTHENTICATED:  false
AUTHENTICATED:  false
    ✓ test connection (3366ms)

  ConnectStore
[MST] /register
credentials 6a219508-83fa-11e8-8d6c-0a580a020292 $T$SVaqnUO6H0zDyQi56UfOuPW/F/rt706fSkgWp1nNKYE=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/setStatus
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /register
[MST] /requestRoster
[MST] /events/load
[MST] /_subscribeToHomestream
credentials 6be43c92-83fa-11e8-bd45-0a580a0203f6 $T$Ustnoy10VMnjRd31QYDZhHvK8VFHN2ulh3hIx56/ymA=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check automatic loading profile
    ✓ check automatic loading profile2
[MST] /profile/update
    ✓ update profile with invalid handle (209ms)
[MST] /profile/update
[MST] /requestRoster
[MST] /events/load
[MST] /profile/update
[MST] /_subscribeToHomestream
[MST] /profile/update
    ✓ update profile (826ms)
[MST] /loadProfile
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/follow
[MST] /addRosterItem
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /addRosterItem
[MST] /loadProfile
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/follow
[MST] /addRosterItem
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/setStatus
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /addRosterItem
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ make them friends (1388ms)
[MST] /createChat
[MST] /chats/_list/0/message/setBody
[MST] /chats/_list/0/message/send
[MST] /chats/_list/0/message/setBody
[MST] /chats/_list/0/message/send
[MST] /_addMessage
[MST] /postProcessSnapshot
[MST] /_addMessage
[MST] /postProcessSnapshot
    ✓ send message (439ms)
[MST] /createChat
[MST] /chats/_list/0/message/upload
[MST] /chats/_list/0/message/send
[MST] /_addMessage
[MST] /files/storage/tros:6a219508-83fa-11e8-8d6c-0a580a020292@testing.dev.tinyrobot.com~0file~06f2226b2-83fa-11e8-95a5-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
[MST] /files/get
[MST] /files/get
    ✓ send media (2370ms)
[MST] /disconnect
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
    ✓ check profile status (226ms)
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /login
[MST] /geofenceBots/load
[MST] /loadChats
[MST] /profiles/get
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/setStatus
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profile/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /profile/postProcessSnapshot
[MST] /postProcessSnapshot
    ✓ check roster (1828ms)
    ✓ check message receive
[MST] /logout
[MST] /requestRoster
[MST] /_loadUpdates
[MST] /register
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
credentials 6be43c92-83fa-11e8-bd45-0a580a0203f6 $T$3eqPMA6ZtXlBqVcBoxnDZDc26PWapcMezjG2ZWs6/Ts=
[MST] /login
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/setStatus
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /profiles/get
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/setStatus
[MST] /profiles/storage/6be43c92-83fa-11e8-bd45-0a580a0203f6/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /requestRoster
[MST] /events/load
[MST] /addRosterItem
[MST] /profiles/storage/6a219508-83fa-11e8-8d6c-0a580a020292/postProcessSnapshot
[MST] /postProcessSnapshot
[MST] /files/get
[MST] /files/get
[MST] /chats/_list/0/load
[MST] /_subscribeToHomestream
[MST] /_addMessage
[MST] /postProcessSnapshot
[MST] /_addMessage
[MST] /postProcessSnapshot
[MST] /_addMessage
    ✓ check conversations (4265ms)
[MST] /remove
[MST] /remove

  78 passing (2m)
  5 failing

  1) BotStore change first bot description and expect new item update:

      AssertionError: expected 0 to equal 1
      + expected - actual

      -0
      +1

      at Object.<anonymous> (test/bot.test.ts:290:42)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/bot.test.ts:288:78)

  2) BotStore incorporate updates:

      AssertionError: expected 2 to equal 3
      + expected - actual

      -2
      +3

      at Object.<anonymous> (test/bot.test.ts:303:41)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/bot.test.ts:299:42)

  3) BotStore logout user2 and login again and verify HS:
     Error: timeout of 30000ms exceeded. Ensure the done() callback is being called in this test.

  4) BotStore disconnect user2 and login again and verify HS, delete items:

      AssertionError: expected 2 to equal 3
      + expected - actual

      -2
      +3

      at Object.<anonymous> (test/bot.test.ts:339:46)
      at Generator.next (<anonymous>)
      at fulfilled (node_modules/tslib/tslib.js:104:62)
      at tryCallOne (node_modules/promise/lib/core.js:37:12)
      at node_modules/promise/lib/core.js:123:15
      at flush (node_modules/asap/raw.js:50:29)
      at _combinedTickCallback (internal/process/next_tick.js:131:7)
      at process._tickCallback (internal/process/next_tick.js:180:9)

  5) BotStore incorporate updates and check bot loading:

      AssertionError: expected 2 to equal 3
      + expected - actual

      -2
      +3

      at Object.<anonymous> (test/bot.test.ts:367:46)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/bot.test.ts:365:64)

npm ERR! code ELIFECYCLE
npm ERR! errno 5
npm ERR! wocky-client@1.0.2 mocha: `mocha -r ts-node/register --require ./test/support/setup.js --timeout 30000 "./test/address.test.ts" "./test/bot.test.ts" "./test/event.test.ts" "./test/factory.test.ts" "./test/file.test.ts" "./test/geofence.test.ts" "./test/graphql.test.ts" "./test/img" "./test/profile.test.ts" "./test/reconnect.test.ts" "./test/support" "./test/xmpp.test.ts"`
npm ERR! Exit status 5
npm ERR! 
npm ERR! Failed at the wocky-client@1.0.2 mocha script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /root/.npm/_logs/2018-07-10T04_33_55_471Z-debug.log
error Command failed with exit code 5.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
aksonov commented 6 years ago

Strange, it was quite reliable during our tests with previously deployed server. And I can't reproduce these errors now (probably because of less loaded server?). Anyway, I found one place where updates were expected almost immediately, without waiting, so probably newer server deploy is a little bit slower. I will fix it.

bernardd commented 6 years ago

Strange, it was quite reliable during our tests with previously deployed server.

Not for me. I've basically never been able to get the tests to run reliably and consistently. That's why we have this item open.

(probably because of less loaded server?)

The servers run at between 1% and 10% CPU. And when I'm doing the tests it's usually somewhere between midnight and 6am in the US where most of our users are. It's difficult to imagine a less loaded situation than what I'm testing in.

so probably newer server deploy is a little bit slower

Could we possibly, just for once, consider a possibility other than "the server is worse than it was before"? I will guarantee you that the communication latency between my house and the server or your house on the server is at least an order of larger than the time it takes the server to process the request. Jumping to the conclusion that the latest deployment is somehow "slower" is not helpful and I can't see how it can be logically justified.

aksonov commented 6 years ago

Not for me. I've basically never been able to get the tests to run reliably and consistently. That's why we have this item open.

So why this ticket is created then only now? I didn't know that it is not stable for you. I use wocky-client tests daily, it helps me a lot (and btw, we found many server-side bugs because of them!) and you can see many green builds within CircleCI (I used 'aksonov' fork last month) and this should prove that tests are quite stable for third-party like CircleCI.

Could we possibly, just for once, consider a possibility other than "the server is worse than it was before"?

We had 'broken tests after new deploy' situation many times and in most cases it meant server-side bug. As I said I found one 'assert' that should be converted 'await waitFor', so I will fix that - I just tried to guess why it passed before.

bernardd commented 6 years ago

So why this ticket is created then only now? I didn't know that it is not stable for you.

Because we weren't using them on any kind of regular basis, so it didn't seem worth it. We didn't want to bug you guys when you already had plenty on your plate.

and this should prove that tests are quite stable for third-party like CircleCI.

It shows that they're stable in one particular, tightly controlled environment, sure.

aksonov commented 6 years ago

Because we weren't using them on any kind of regular basis, so it didn't seem worth it. We didn't want to bug you guys when you already had plenty on your plate.

Hm, but they should be used on regular basis because we have situation like recent bug with live subscriptions from time to time and I tired to prove that 'it is server, not client' every time...

It shows that they're stable in one particular, tightly controlled environment, sure.

Sorry, but it is "typical" Node/npm/ReactNative/Javascript, I can't do much here...

aksonov commented 6 years ago

@toland, @bernardd I just pushed small improvement within bot.test.js to fix rare failures Bernard met, please check. There are some things to do (use randomized phoneNumbers, handles anywhere), but this version should be stable enough too

toland commented 6 years ago

First, I need to second Bernard's experience with running the wocky-client test suite. I try to run it after every testing deploy, but it is rare that I get a clean run. I will then follow-up with Eric, and after some mutual poking around and head-scratching, we will jointly come to the conclusion that the server is running fine and something weird is going on with the tests. This has happened enough times that I have learned to not trust those tests.

Second, while the tests may be transparent to Pavel and Eric, they are opaque to Bernard and me. This is very important and a factor that I feel like has been overlooked and/or dismissed. Bernard and I are not familiar with the client code. And there is a lot of code between the test and the actual interaction with the server. Right now, if the wocky-client tests fail, all that it tells us is that "something is wrong, somewhere, maybe." Does a failure mean that there is a problem with the server? Is it a problem with the client code? Maybe the test itself is brittle? We don't know the answer to those questions. And saying "the tests passed before" is an interesting data point, but not an answer.

Let me give you an example:

  1) GraphQL get credentials via XMPP:
     Error: timeout of 30000ms exceeded. Ensure the done() callback is being called in this test.

This is a test failure that I got several times. What does this mean? What server operation was called? What results came back (or didn't) and what was the expected result? This result gives me nothing to work with. I have to go spelunking through the tests and client code to even begin to piece together a picture of what is happening. And all of this is before I can even begin to diagnose the issue.

Here is another example:

  2) GraphQL loads profile:
     TypeError: Cannot read property 'loadProfile' of undefined
      at Object.<anonymous> (test/graphql.test.ts:41:33)
      at Generator.next (<anonymous>)
      at node_modules/tslib/tslib.js:107:75
      at tryCallTwo (node_modules/promise/lib/core.js:45:5)
      at doResolve (node_modules/promise/lib/core.js:200:13)
      at new Promise (node_modules/promise/lib/core.js:66:3)
      at Object.__awaiter (node_modules/tslib/tslib.js:103:16)
      at Context.it (test/graphql.test.ts:39:36)

This error happens a lot. My best reading of this is that the client and/or test code is trying to read a property from a null object. While the root cause of that may be an issue with the server, we have to first solve a client/test problem before we can get to any potential underlying server problems.

My point is that, as they are now, the wocky-client tests are unsuitable for us to use as a diagnostic tool, as we are being asked to do. Identifying that there is a server problem is only the first step, then you have to actually identify the actual problem. I have much more to say on that topic, but I think it is an open question as to whether or not we really want to use the wocky-client tests as a diagnostic tool for potential server-side issues. The changes necessary might be more onerous than they are worth when there are other alternatives available.

aksonov commented 6 years ago

Wacky-client unit tests were designed to check client-side, not server side code. I guess you have own unit tests. I proposed to run them not as diagnostic tool but as ‘something is wrong’ flag (with high probability on server side) to prevent live subscription failures or other server failures we had in the past.If you have better idea how not to break the app after new server deploy let me know.

On 10 Jul 2018, at 20:45, Phil Toland notifications@github.com wrote:

First, I need to second Bernard's experience with running the wocky-client test suite. I try to run it after every testing deploy, but it is rare that I get a clean run. I will then follow-up with Eric, and after some mutual poking around and head-scratching, we will jointly come to the conclusion that the server is running fine and something weird is going on with the tests. This has happened enough times that I have learned to not trust those tests.

Second, while the tests may be transparent to Pavel and Eric, they are opaque to Bernard and me. This is very important and a factor that I feel like has been overlooked and/or dismissed. Bernard and I are not familiar with the client code. And there is a lot of code between the test and the actual interaction with the server. Right now, if the wocky-client tests fail, all that it tells us is that "something is wrong, somewhere, maybe." Does a failure mean that there is a problem with the server? Is it a problem with the client code? Maybe the test itself is brittle? We don't know the answer to those questions. And saying "the tests passed before" is an interesting data point, but not an answer.

Let me give you an example:

1) GraphQL get credentials via XMPP: Error: timeout of 30000ms exceeded. Ensure the done() callback is being called in this test. This is a test failure that I got several times. What does this mean? What server operation was called? What results came back (or didn't) and what was the expected result? This result gives me nothing to work with. I have to go spelunking through the tests and client code to even begin to piece together a picture of what is happening. And all of this is before I can even begin to diagnose the issue.

Here is another example:

2) GraphQL loads profile: TypeError: Cannot read property 'loadProfile' of undefined at Object. (test/graphql.test.ts:41:33) at Generator.next () at node_modules/tslib/tslib.js:107:75 at tryCallTwo (node_modules/promise/lib/core.js:45:5) at doResolve (node_modules/promise/lib/core.js:200:13) at new Promise (node_modules/promise/lib/core.js:66:3) at Object.__awaiter (node_modules/tslib/tslib.js:103:16) at Context.it (test/graphql.test.ts:39:36) This error happens a lot. My best reading of this is that the client and/or test code is trying to read a property from a null object. While the root cause of that may be an issue with the server, we have to first solve a client/test problem before we can get to any potential underlying server problems.

My point is that, as they are now, the wocky-client tests are unsuitable for us to use as a diagnostic tool, as we are being asked to do. Identifying that there is a server problem is only the first step, then you have to actually identify the actual problem. I have much more to say on that topic, but I think it is an open question as to whether or not we really want to use the wocky-client tests as a diagnostic tool for potential server-side issues. The changes necessary might be more onerous than they are worth when there are other alternatives available.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

aksonov commented 6 years ago

And I didn’t get such errors like you wrote against normally working server - please create wocky-client ticket if you get any. So far one unstable test I saw was upload image test - probably sometimes amazon postprocessing takes too long..

On 10 Jul 2018, at 20:45, Phil Toland notifications@github.com wrote:

First, I need to second Bernard's experience with running the wocky-client test suite. I try to run it after every testing deploy, but it is rare that I get a clean run. I will then follow-up with Eric, and after some mutual poking around and head-scratching, we will jointly come to the conclusion that the server is running fine and something weird is going on with the tests. This has happened enough times that I have learned to not trust those tests.

Second, while the tests may be transparent to Pavel and Eric, they are opaque to Bernard and me. This is very important and a factor that I feel like has been overlooked and/or dismissed. Bernard and I are not familiar with the client code. And there is a lot of code between the test and the actual interaction with the server. Right now, if the wocky-client tests fail, all that it tells us is that "something is wrong, somewhere, maybe." Does a failure mean that there is a problem with the server? Is it a problem with the client code? Maybe the test itself is brittle? We don't know the answer to those questions. And saying "the tests passed before" is an interesting data point, but not an answer.

Let me give you an example:

1) GraphQL get credentials via XMPP: Error: timeout of 30000ms exceeded. Ensure the done() callback is being called in this test. This is a test failure that I got several times. What does this mean? What server operation was called? What results came back (or didn't) and what was the expected result? This result gives me nothing to work with. I have to go spelunking through the tests and client code to even begin to piece together a picture of what is happening. And all of this is before I can even begin to diagnose the issue.

Here is another example:

2) GraphQL loads profile: TypeError: Cannot read property 'loadProfile' of undefined at Object. (test/graphql.test.ts:41:33) at Generator.next () at node_modules/tslib/tslib.js:107:75 at tryCallTwo (node_modules/promise/lib/core.js:45:5) at doResolve (node_modules/promise/lib/core.js:200:13) at new Promise (node_modules/promise/lib/core.js:66:3) at Object.__awaiter (node_modules/tslib/tslib.js:103:16) at Context.it (test/graphql.test.ts:39:36) This error happens a lot. My best reading of this is that the client and/or test code is trying to read a property from a null object. While the root cause of that may be an issue with the server, we have to first solve a client/test problem before we can get to any potential underlying server problems.

My point is that, as they are now, the wocky-client tests are unsuitable for us to use as a diagnostic tool, as we are being asked to do. Identifying that there is a server problem is only the first step, then you have to actually identify the actual problem. I have much more to say on that topic, but I think it is an open question as to whether or not we really want to use the wocky-client tests as a diagnostic tool for potential server-side issues. The changes necessary might be more onerous than they are worth when there are other alternatives available.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

toland commented 6 years ago

(probably because of less loaded server?)

As Bernard pointed out, the server load on our clusters is negligible. The cluster worker nodes and the database nodes are all using very little CPU and have a very low loadavg. Server load is almost certainly not a factor here.

so probably newer server deploy is a little bit slower

Any variations in mainline performance between deploys will be dwarfed by the normal variations in network and database performance. Our application is overwhelmingly bound by network and database IO. The client should be resilient to spikes in network latency, as they will happen and are almost entirely out of our control.

I use wocky-client tests daily, it helps me a lot

I have no doubt of that, and I am glad that they are useful to you. The point of this discussion is that we are being asked to use them as a diagnostic tool and finding that they are not so helpful for us.

you can see many green builds within CircleCI (I used 'aksonov' fork last month) and this should prove that tests are quite stable for third-party like CircleCI.

I do not think that this statement is as definitive as you seem to think. Saying "the tests run fine on CircleCI" is not an effective response to "the test fail in mysterious ways when I run them." The is the old saw where a programmer says "but it works fine on my machine" when presented with evidence that their code is misbehaving in the wild.

but they should be used on regular basis because we have situation like recent bug with live subscriptions from time to time

Not if they don't add value to the process. Between Bernard and I we spent 3 days working to find an issue that could have been resolved in an afternoon because we had to diagnose the wocky-client test suite first. It should come as no surprise that having to diagnose code that was written by someone else in a language that we are unfamiliar with was not a rewarding or productive experience. In this case, the tests were a net-negative, not a positive, part of the process.

and I tired to prove that 'it is server, not client' every time...

Perhaps it would be more productive, and better for everyone involved, if the goal was to work together to find and resolve issues rather than to "prove that 'it is server, not client' every time." We are on the same team here. Forget "frontend team" and "backend team", we are all on the "Hippware team" trying to deliver one application. The internal division of that application into a server and client component is irrelevant to our users and to our success as a company. I don't find allocating blame to be all that productive, especially in this environment where we are moving fast, requirements are fuzzy, and communication is...perhaps not what it should be.

I think that I can speak for both myself and Bernard when I say that we want, above all else, to deliver the best server code that we can in the least time. This will involve tradeoffs, and there will be problems along the way. If there is a problem with the server, then we definitely want to fix it. But we need y'all's help to do that. Saying "the server is broken and the tests prove it" is...unhelpful at best and at worst counterproductive. And throwing around words like "buggy" and "broken" is inflammatory and doesn't get the problem solved any faster. (BTW, I changed the title to this issue because I felt the old title did not adequately express what I wanted to see here).

When Bernard and I push back on a bug report, it isn't because we want to "prove it is the client, not the server", it is because we are struggling to see how the server is not performing as expected. We need your help with that. If the wocky-client test suite can be part of that solution, great. But it isn't enough by itself.

aksonov commented 6 years ago

Any variations in mainline performance between deploys will be dwarfed by the normal variations in network and database performance. Our application is overwhelmingly bound by network and database IO. The client should be resilient to spikes in network latency, as they will happen and are almost entirely out of our control.

Ugh, could you re-read my statement again? I just said I found one possible reason for particular failures Bernard got. I agree that the client should be resilient (so I said "I will fix it"), I don't understand why you and Bernard want to comment every my wording even if it is NOT related to main problem - server failures. All I see that server deploy fails from time to time and my working day is totally broken. I suggested to use wocky-client tests maybe year ago or more to prevent it, you just ignored it (without any explanation?) - and finally only now I got needed details ('not stable', 'not informative')

I do not think that this statement is as definitive as you seem to think. Saying "the tests run fine on CircleCI" is not an effective response to "the test fail in mysterious ways when I run them." The is the old saw where a programmer says "but it works fine on my machine" when presented with evidence that their code is misbehaving in the wild.

Funny, but I can say exactly the same about you - the your and Bernard's statements "these tests fails on my machine" look VERY similar to that old saw "it works fine on my machine". Tests work fine on my machine/Eric's machine and finally third-party CircleCI machine (as well as on Nevercode, AppCenter servers). Sure it means that they require some proper environment to be set. Also it means that tests are stable enough and don't just 'work fine on my machine'.

I think that I can speak for both myself and Bernard when I say that we want, above all else, to deliver the best server code that we can in the least time. This will involve tradeoffs, and there will be problems along the way. If there is a problem with the server, then we definitely want to fix it. But we need y'all's help to do that. ... When Bernard and I push back on a bug report, it isn't because we want to "prove it is the client, not the server", it is because we are struggling to see how the server is not performing as expected. We need your help with that. If the wocky-client test suite can be part of that solution, great. But it isn't enough by itself.

Okey, at least I proposed some solution (about running wocky-client tests) - it means I really want to help and ALSO I want to be productive and not to be interrupted by server failures (I was not able to finish 'invisible mode' for several days because of it). What was your suggestion to prevent it? Maybe I missed it.

Also I didn't received any asking of any help. Only short but quite useful note from Beng(!) "This server side release has a lot of changes. Amongst other things, there was a change in the Erlang/Elixir versions. Not expecting things to break, but this is more uncertain and more variable than usual." Looks like development channel now contains standups / server deploy notifications, but nothing like "Pavel/Eric, could you please check if everything works well after new deploy, we tried to run wocky-client tests but it failed on our machines (and we didn't know anything about circleci)"

Perhaps it would be more productive, and better for everyone involved, if the goal was to work together to find and resolve issues rather than to "prove that 'it is server, not client' every time." We are on the same team here. Forget "frontend team" and "backend team", we are all on the "Hippware team" trying to deliver one application. The internal division of that application into a server and client component is irrelevant to our users and to our success as a company. I don't find allocating blame to be all that productive, especially in this environment where we are moving fast, requirements are fuzzy, and communication is...perhaps not what it should be.

Fully agree about one team - and that is why I wonder why I should discover strange issues at the beginning of my working day with only short note from Beng, nothing from you/Bernard (that live subscriptions or other may fail and you possible need help, etc). Why I saw total silence within development channel today after investigation of these issues. Why I didn't see any explanation what the bug was. So I see irony here - I don't see that you and Bernard share problems with us and behave as one team. Also note, even after I raised the problem with failed unit tests (even after I said that 'live subscriptions' fails in stable way), I got your "... Other than that, there are no other errors of note in the log files. I fired up GraphiQL and verified that I can connect to the testing server and run queries.".. Also I got the same answer (something like "server works normally") for previous server-side bug too few months ago. So I don't see any collaborative work here. I wanted to help, I even told that the client didn't receive live subscriptions but it didn't help at all (you started complaining that tests were not informative and outputs 'timeout' etc.) I don't understand what is going on here. It is probably something is wrong on server-side code logging if you can't see problems even after I told where is the problem (live subscription for last deploy). And it is not first time when it happens, so we must finally do something to FIX it.

aksonov commented 6 years ago

Also one note - usually Bernard's working day is finished when I discover something (thanks to Bernard, he tried to help after dinner). It means that I stuck during several hours and had to wait for Bernard's response. So I don't understand why not to deploy new server only when somebody (Eric or me) is active so we can validate it immediately?

bengtan commented 6 years ago

Okay, everyone, let's cool down a bit please. I see things are getting heated. It's not on fire yet, but it's getting that way if things continue as they are.

As a temporary measure, I'll (when I have time) have a look at the reported issues in the client side tests. I'll try to reproduce and then diagnose them. I'm on both teams so I don't have this 'us vs them' conflict.

After that, we'll make a decision on how useful they are for the back-end devs to use it as a tool.

In the meantime, this discussion can continue if you guys have more things to say, but please keep the heat out of it.

bengtan commented 6 years ago

Closing this ticket because it has gone off-topic and slightly toxic. Replacement is #2566.