Rules blocked across apps on self hosted solutions

arnfasto · October 28, 2020, 9:30am

Hi Sebastian

We have alot of events > 400.000 that’s we re-ran a rule and started processing yesterday ( which took a while ), but itseems to have worked. Now however we are not able to get a list of the rule logs, it’s just pending. Any thougts on that?

On a second note, i can see in the logs that it try to run a rule that no longer exist ( and to an endpoint that doesn’t exist ) and it seems like it blocking rules across apps. Do you have idea what to do, to get back on track and get the rules working again?

We are hosting it locally, but assume that the problem is something that would also accour in your cloud solution.

Sebastian · October 28, 2020, 8:32pm

I have not seen this issue before, but I know that at least one customer has run across 5 Mio events through the rules and it was working fine. The rule logs is not meant to be complete, for example there old logs get deleted after 30 days or so.

arnfasto · October 28, 2020, 8:48pm

I just see this in one of the app that have run 400.000 events.

Another app i can see the events but have this:

The only thing in the logs is that it’s trying to send a request to a webhook that belong to a rule that we have deleted

arnfasto · October 28, 2020, 9:37pm

2020-10-28T21:35:18.723820506Z {
2020-10-28T21:35:18.723844206Z   "logLevel": "Information",
2020-10-28T21:35:18.723848106Z   "message": "Sending HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.723852006Z   "eventId": {
2020-10-28T21:35:18.723855706Z     "id": 100,
2020-10-28T21:35:18.723859406Z     "name": "RequestStart"
2020-10-28T21:35:18.723863106Z   },
2020-10-28T21:35:18.723866706Z   "httpMethod": "POST",
2020-10-28T21:35:18.730832326Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.730850926Z   "app": {
2020-10-28T21:35:18.730856826Z     "name": "Squidex",
2020-10-28T21:35:18.730861426Z     "version": "4.7.5.0",
2020-10-28T21:35:18.730865826Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.730870426Z   },
2020-10-28T21:35:18.730874526Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.730878926Z   "category": "System.Net.Http.HttpClient.Default.ClientHandler"
2020-10-28T21:35:18.730883326Z }
2020-10-28T21:35:18.730887426Z 
2020-10-28T21:35:18.739807252Z {
2020-10-28T21:35:18.739839553Z   "logLevel": "Information",
2020-10-28T21:35:18.739846053Z   "message": "Start processing HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.739850653Z   "eventId": {
2020-10-28T21:35:18.739854753Z     "id": 100,
2020-10-28T21:35:18.739858853Z     "name": "RequestPipelineStart"
2020-10-28T21:35:18.739863153Z   },
2020-10-28T21:35:18.739867053Z   "httpMethod": "POST",
2020-10-28T21:35:18.749675081Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.749692381Z   "app": {
2020-10-28T21:35:18.749698181Z     "name": "Squidex",
2020-10-28T21:35:18.749702281Z     "version": "4.7.5.0",
2020-10-28T21:35:18.749706281Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.749710581Z   },
2020-10-28T21:35:18.749749581Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.749755481Z   "category": "System.Net.Http.HttpClient.Default.LogicalHandler"
2020-10-28T21:35:18.749759581Z }
2020-10-28T21:35:18.749763381Z 
2020-10-28T21:35:18.749782981Z {
2020-10-28T21:35:18.749786881Z   "logLevel": "Information",
2020-10-28T21:35:18.749790581Z   "message": "Sending HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.749794581Z   "eventId": {
2020-10-28T21:35:18.749807582Z     "id": 100,
2020-10-28T21:35:18.749811182Z     "name": "RequestStart"
2020-10-28T21:35:18.749814982Z   },
2020-10-28T21:35:18.749818482Z   "httpMethod": "POST",
2020-10-28T21:35:18.749822382Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.749826182Z   "app": {
2020-10-28T21:35:18.749829882Z     "name": "Squidex",
2020-10-28T21:35:18.749833682Z     "version": "4.7.5.0",
2020-10-28T21:35:18.749837382Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.749841182Z   },
2020-10-28T21:35:18.749844682Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.749848582Z   "category": "System.Net.Http.HttpClient.Default.ClientHandler"
2020-10-28T21:35:18.749852382Z }
2020-10-28T21:35:18.749856482Z 
2020-10-28T21:35:18.771637245Z {
2020-10-28T21:35:18.771658845Z   "logLevel": "Information",
2020-10-28T21:35:18.771664945Z   "message": "Start processing HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.771669645Z   "eventId": {
2020-10-28T21:35:18.771673945Z     "id": 100,
2020-10-28T21:35:18.771678245Z     "name": "RequestPipelineStart"
2020-10-28T21:35:18.771682745Z   },
2020-10-28T21:35:18.771686945Z   "httpMethod": "POST",
2020-10-28T21:35:18.774794454Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.774811354Z   "app": {
2020-10-28T21:35:18.774817354Z     "name": "Squidex",
2020-10-28T21:35:18.774830754Z     "version": "4.7.5.0",
2020-10-28T21:35:18.774835954Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.774840354Z   },
2020-10-28T21:35:18.774844454Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.774848654Z   "category": "System.Net.Http.HttpClient.Default.LogicalHandler"
2020-10-28T21:35:18.774852854Z }
2020-10-28T21:35:18.774856754Z 
2020-10-28T21:35:18.774860754Z {
2020-10-28T21:35:18.774874255Z   "logLevel": "Information",
2020-10-28T21:35:18.774879155Z   "message": "Sending HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.774883455Z   "eventId": {
2020-10-28T21:35:18.774904055Z     "id": 100,
2020-10-28T21:35:18.774908155Z     "name": "RequestStart"
2020-10-28T21:35:18.774928955Z   },
2020-10-28T21:35:18.774932755Z   "httpMethod": "POST",
2020-10-28T21:35:18.774936755Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.774940755Z   "app": {
2020-10-28T21:35:18.774944455Z     "name": "Squidex",
2020-10-28T21:35:18.774948255Z     "version": "4.7.5.0",
2020-10-28T21:35:18.774952155Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.774956055Z   },
2020-10-28T21:35:18.774959655Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.774963555Z   "category": "System.Net.Http.HttpClient.Default.ClientHandler"
2020-10-28T21:35:18.774967455Z }
2020-10-28T21:35:18.774971155Z 
2020-10-28T21:35:18.792706406Z {
2020-10-28T21:35:18.792723306Z   "logLevel": "Information",
2020-10-28T21:35:18.792728706Z   "message": "Start processing HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.792732806Z   "eventId": {
2020-10-28T21:35:18.792736506Z     "id": 100,
2020-10-28T21:35:18.792786107Z     "name": "RequestPipelineStart"
2020-10-28T21:35:18.792795807Z   },
2020-10-28T21:35:18.792799907Z   "httpMethod": "POST",
2020-10-28T21:35:18.799220925Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.799248125Z   "app": {
2020-10-28T21:35:18.799254325Z     "name": "Squidex",
2020-10-28T21:35:18.799258325Z     "version": "4.7.5.0",
2020-10-28T21:35:18.799262425Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.799266626Z   },
2020-10-28T21:35:18.799270426Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.799274426Z   "category": "System.Net.Http.HttpClient.Default.LogicalHandler"
2020-10-28T21:35:18.799278526Z }
2020-10-28T21:35:18.799282226Z 
2020-10-28T21:35:18.799285826Z {
2020-10-28T21:35:18.799289526Z   "logLevel": "Information",
2020-10-28T21:35:18.799293326Z   "message": "Sending HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.799297226Z   "eventId": {
2020-10-28T21:35:18.799301026Z     "id": 100,
2020-10-28T21:35:18.799304726Z     "name": "RequestStart"
2020-10-28T21:35:18.799318426Z   },
2020-10-28T21:35:18.799322326Z   "httpMethod": "POST",
2020-10-28T21:35:18.799326126Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:18.799329926Z   "app": {
2020-10-28T21:35:18.799333626Z     "name": "Squidex",
2020-10-28T21:35:18.799337726Z     "version": "4.7.5.0",
2020-10-28T21:35:18.799341626Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:18.799345226Z   },
2020-10-28T21:35:18.799348826Z   "timestamp": "2020-10-28T21:35:18Z",
2020-10-28T21:35:18.799352526Z   "category": "System.Net.Http.HttpClient.Default.ClientHandler"
2020-10-28T21:35:18.799356426Z }
2020-10-28T21:35:18.799359826Z 
2020-10-28T21:35:19.042436433Z {
2020-10-28T21:35:19.042464733Z   "logLevel": "Information",
2020-10-28T21:35:19.042470233Z   "message": "Start processing HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.042474434Z   "eventId": {
2020-10-28T21:35:19.042478034Z     "id": 100,
2020-10-28T21:35:19.042481634Z     "name": "RequestPipelineStart"
2020-10-28T21:35:19.042491634Z   },
2020-10-28T21:35:19.042496234Z   "httpMethod": "POST",
2020-10-28T21:35:19.042500134Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.042504034Z   "app": {
2020-10-28T21:35:19.042507434Z     "name": "Squidex",
2020-10-28T21:35:19.042511134Z     "version": "4.7.5.0",
2020-10-28T21:35:19.042514734Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:19.042518534Z   },
2020-10-28T21:35:19.042521834Z   "timestamp": "2020-10-28T21:35:19Z",
2020-10-28T21:35:19.042525434Z   "category": "System.Net.Http.HttpClient.Default.LogicalHandler"
2020-10-28T21:35:19.042529034Z }
2020-10-28T21:35:19.042532434Z 
2020-10-28T21:35:19.042535734Z {
2020-10-28T21:35:19.042539134Z   "logLevel": "Information",
2020-10-28T21:35:19.042542834Z   "message": "Sending HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.042546434Z   "eventId": {
2020-10-28T21:35:19.042549834Z     "id": 100,
2020-10-28T21:35:19.042553234Z     "name": "RequestStart"
2020-10-28T21:35:19.042557134Z   },
2020-10-28T21:35:19.042560534Z   "httpMethod": "POST",
2020-10-28T21:35:19.042564034Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.042567634Z   "app": {
2020-10-28T21:35:19.042579134Z     "name": "Squidex",
2020-10-28T21:35:19.042583134Z     "version": "4.7.5.0",
2020-10-28T21:35:19.042586634Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:19.042590034Z   },
2020-10-28T21:35:19.042593234Z   "timestamp": "2020-10-28T21:35:19Z",
2020-10-28T21:35:19.042596734Z   "category": "System.Net.Http.HttpClient.Default.ClientHandler"
2020-10-28T21:35:19.042600334Z }
2020-10-28T21:35:19.042603534Z 
2020-10-28T21:35:19.257972561Z {
2020-10-28T21:35:19.258028561Z   "logLevel": "Information",
2020-10-28T21:35:19.258037361Z   "message": "Start processing HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.258042161Z   "eventId": {
2020-10-28T21:35:19.258046161Z     "id": 100,
2020-10-28T21:35:19.258050061Z     "name": "RequestPipelineStart"
2020-10-28T21:35:19.258054261Z   },
2020-10-28T21:35:19.258057961Z   "httpMethod": "POST",
2020-10-28T21:35:19.262875975Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.262893275Z   "app": {
2020-10-28T21:35:19.262898675Z     "name": "Squidex",
2020-10-28T21:35:19.262902775Z     "version": "4.7.5.0",
2020-10-28T21:35:19.262906875Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:19.262911075Z   },
2020-10-28T21:35:19.262914675Z   "timestamp": "2020-10-28T21:35:19Z",
2020-10-28T21:35:19.262927375Z   "category": "System.Net.Http.HttpClient.Default.LogicalHandler"
2020-10-28T21:35:19.262932675Z }
2020-10-28T21:35:19.262936275Z 
2020-10-28T21:35:19.262940275Z {
2020-10-28T21:35:19.262943875Z   "logLevel": "Information",
2020-10-28T21:35:19.262947675Z   "message": "Sending HTTP request POST https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.262951775Z   "eventId": {
2020-10-28T21:35:19.262955475Z     "id": 100,
2020-10-28T21:35:19.262959275Z     "name": "RequestStart"
2020-10-28T21:35:19.262962975Z   },
2020-10-28T21:35:19.262966575Z   "httpMethod": "POST",
2020-10-28T21:35:19.262970375Z   "uri": "https://e9750d1deaf9.ngrok.io/api/CdbWebhookPipe",
2020-10-28T21:35:19.262974175Z   "app": {
2020-10-28T21:35:19.262977875Z     "name": "Squidex",
2020-10-28T21:35:19.262981575Z     "version": "4.7.5.0",
2020-10-28T21:35:19.262985275Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:19.263006075Z   },
2020-10-28T21:35:19.263009776Z   "timestamp": "2020-10-28T21:35:19Z",
2020-10-28T21:35:19.263028776Z   "category": "System.Net.Http.HttpClient.Default.ClientHandler"
2020-10-28T21:35:19.263033176Z }
2020-10-28T21:35:19.263036876Z 

2020-10-28T21:35:22.948931672Z {
2020-10-28T21:35:22.949391174Z   "logLevel": "Information",
2020-10-28T21:35:22.949822577Z   "filters": {
2020-10-28T21:35:22.950103878Z     "appId": "6b8664ac-d92d-4b0b-90b7-86920b49643f",
2020-10-28T21:35:22.950117178Z     "appName": "arla-se",
2020-10-28T21:35:22.950122178Z     "userId": "5d8b14269bfbbf0001e53bca",
2020-10-28T21:35:22.950126678Z     "clientId": "squidex-frontend",
2020-10-28T21:35:22.950131178Z     "costs": 0.1
2020-10-28T21:35:22.950135378Z   },
2020-10-28T21:35:22.950139578Z   "elapsedRequestMs": 4,
2020-10-28T21:35:22.950303079Z   "app": {
2020-10-28T21:35:22.950314379Z     "name": "Squidex",
2020-10-28T21:35:22.950319179Z     "version": "4.7.5.0",
2020-10-28T21:35:22.950323579Z     "sessionId": "75515776-3ffa-417e-b2db-a1493bb1c3db"
2020-10-28T21:35:22.950328079Z   },
2020-10-28T21:35:22.950332179Z   "web": {
2020-10-28T21:35:22.950336379Z     "requestId": "|c0de7097-47591eaa851e26ae.",
2020-10-28T21:35:22.950350679Z     "requestPath": "/api/apps/arla-se/history",
2020-10-28T21:35:22.950356679Z     "requestMethod": "GET"
2020-10-28T21:35:22.950361179Z   },
2020-10-28T21:35:22.950365179Z   "timestamp": "2020-10-28T21:35:22Z"
2020-10-28T21:35:22.950369679Z }

Sebastian · October 29, 2020, 8:04am

The interesting things are the retries. I think what could happen:

You get a lot of event
Most events fail and go into retry
The retry events are executed again (because they are also inserted first) before other events that have not been tried yet.

arnfasto · October 29, 2020, 8:17am

I think is very plausible, short term, is there a collection or something we can clear to get back to normal?

Long term let me know if i can assist you in anything to figure out what is happening

Sebastian · October 29, 2020, 8:18am

What is normal? What do you expect to happen?

arnfasto · October 29, 2020, 8:26am

It’s in test environment, so now we just want our rules to work again, since now this issue is blocking all our sync to external systems

Sebastian · October 29, 2020, 8:28am

But the question is: why are they in retry?

arnfasto · October 29, 2020, 8:39am

In this case is because the endpoint they try to reach don’t exist since it has been taken down (it’s a temporary proxy endpoint for test purpose, ngrok.io ), so it will never succeed

Sebastian · October 29, 2020, 9:08am

But then everything is okay. You can clear the Ruleevents collection if you want.

arnfasto · October 29, 2020, 5:25pm

It started working again after rulevents was deleted