Mongo timeouts and long request logging (#2891)

Signed-off-by: Andrey Sobolev <haiodo@gmail.com>

models/all/src/version.json

@@ -1 +1 @@
-{ "major": 0, "minor": 6, "patch": 73 }
+{ "major": 0, "minor": 6, "patch": 78 }

models/bitrix/src/index.ts

@@ -14,22 +14,26 @@
 // limitations under the License.
 //
 
-import { ArrOf, Builder, Collection, Mixin, Model, Prop, TypeRef, TypeString } from '@hcengineering/model'
+import { ArrOf, Builder, Collection, Mixin, Model, Prop, ReadOnly, TypeRef, TypeString, UX } from '@hcengineering/model'
 import core, { TAttachedDoc, TDoc } from '@hcengineering/model-core'
 import bitrix from './plugin'
 
 import { BitrixEntityMapping, BitrixFieldMapping, BitrixSyncDoc, Fields } from '@hcengineering/bitrix'
-import { AnyAttribute, Class, Doc, Domain, Mixin as CoreMixin, Ref } from '@hcengineering/core'
+import { AnyAttribute, Class, Mixin as CoreMixin, Doc, Domain, Ref } from '@hcengineering/core'
 
 import view, { createAction } from '@hcengineering/model-view'
 
+import { getEmbeddedLabel } from '@hcengineering/platform'
 import setting from '@hcengineering/setting'
 
 const DOMAIN_BITRIX = 'bitrix' as Domain
 
 @Mixin(bitrix.mixin.BitrixSyncDoc, core.class.Doc)
+@UX(getEmbeddedLabel('Bitrix'))
 export class TBitrixSyncDoc extends TDoc implements BitrixSyncDoc {
   type!: string
+  @Prop(TypeString(), getEmbeddedLabel('BitrixId'))
+  @ReadOnly()
     bitrixId!: string
 }
 

models/core/src/core.ts

@@ -90,12 +90,15 @@ export class TDoc extends TObj implements Doc {
     space!: Ref<Space>
 
   @Prop(TypeTimestamp(), core.string.Modified)
+  @Index(IndexKind.Indexed)
     modifiedOn!: Timestamp
 
   @Prop(TypeRef(core.class.Account), core.string.ModifiedBy)
+  @Index(IndexKind.Indexed)
     modifiedBy!: Ref<Account>
 
   @Prop(TypeRef(core.class.Account), core.string.CreatedBy)
+  @Index(IndexKind.Indexed)
     createdBy!: Ref<Account>
 }
 

models/tracker/src/index.ts

@@ -207,6 +207,7 @@ export class TIssue extends TAttachedDoc implements Issue {
     blockedBy!: RelatedDocument[]
 
   @Prop(ArrOf(TypeRef(core.class.TypeRelatedDocument)), tracker.string.RelatedTo)
+  @Index(IndexKind.Indexed)
     relations!: RelatedDocument[]
 
   parents!: IssueParentInfo[]

pods/server/Dockerfile

@@ -5,4 +5,4 @@ WORKDIR /usr/src/app
 COPY bundle.js ./
 
 EXPOSE 8080
-CMD [ "node", "--enable-source-maps", "bundle.js" ]
+CMD [ "node", "--enable-source-maps", "--inspect", "bundle.js" ]

pods/server/package.json

@@ -14,7 +14,8 @@
     "docker:push": "../../common/scripts/docker_tag.sh hardcoreeng/transactor",
     "build:watch": "tsc",
     "lint": "eslint src",
-    "format": "prettier --write src && eslint --fix src"
+    "format": "prettier --write src && eslint --fix src",
+    "docker:tbuild": "docker build -t hardcoreeng/transactor . --platform=linux/amd64 && ../../common/scripts/docker_tag_push.sh hardcoreeng/transactor"
   },
   "devDependencies": {
     "cross-env": "~7.0.3",

server/mongo/src/storage.ts

@@ -408,6 +408,7 @@ abstract class MongoAdapterBase implements DbAdapter {
     })
     const domain = this.hierarchy.getDomain(clazz)
     const cursor = this.db.collection(domain).aggregate(pipeline)
+    cursor.maxTimeMS(30000)
     const res = (await cursor.toArray())[0]
     const result = res.results as WithLookup<T>[]
     const total = res.totalCount?.shift()?.count
@@ -529,6 +530,11 @@ abstract class MongoAdapterBase implements DbAdapter {
         cursor = cursor.limit(options.limit)
       }
     }
+
+    // Error in case of timeout
+    cursor.maxTimeMS(30000)
+    cursor.maxAwaitTimeMS(30000)
+
     const res = await cursor.toArray()
     return toFindResult(res, total)
   }

server/ws/src/server.ts

@@ -319,7 +319,8 @@ async function handleRequest<S extends Session> (
   ctx: MeasureContext,
   service: S,
   ws: WebSocket,
-  msg: string
+  msg: string,
+  workspace: string
 ): Promise<void> {
   const request = readRequest(msg)
   if (request.id === -1 && request.method === 'hello') {
@@ -336,10 +337,36 @@ async function handleRequest<S extends Session> (
   const f = (service as any)[request.method]
   try {
     const params = [userCtx, ...request.params]
+
+    const st = Date.now()
+    const timeout = setTimeout(() => {
+      console.log('long request found', workspace, service.getUser(), request, params)
+    }, 4000)
+
+    const hangTimeout = setTimeout(() => {
+      console.log('request hang found, 30sec', workspace, service.getUser(), request, params)
+    }, 30000)
+
     const result = await f.apply(service, params)
+    clearTimeout(timeout)
+    clearTimeout(hangTimeout)
     const resp: Response<any> = { id: request.id, result }
+
+    const diff = Date.now() - st
+    if (diff > 5000) {
+      console.log(
+        'very long request found',
+        workspace,
+        service.getUser(),
+        request,
+        params,
+        Array.isArray(result) ? result.length : '0',
+        diff
+      )
+    }
     ws.send(serialize(resp))
   } catch (err: any) {
+    console.error(err)
     const resp: Response<any> = {
       id: request.id,
       error: unknownError(err)
@@ -398,7 +425,7 @@ export function start (
       } else if (Array.isArray(msg)) {
         msgStr = Buffer.concat(msg).toString()
       }
-      await handleRequest(ctx, session, ws, msgStr)
+      await handleRequest(ctx, session, ws, msgStr, token.workspace.name)
     })
     // eslint-disable-next-line @typescript-eslint/no-misused-promises
     ws.on('close', (code: number, reason: Buffer) => {
@@ -420,7 +447,7 @@ export function start (
     const b = buffer
     buffer = undefined
     for (const msg of b) {
-      await handleRequest(ctx, session, ws, msg)
+      await handleRequest(ctx, session, ws, msg, token.workspace.name)
     }
   })