search cancel

[FATAL] ASYNC_SERVICES is down

book

Article ID: 243661

calendar_today

Updated On:

Products

Web Isolation

Issue/Introduction

May  5 09:29:46 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:29:46 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:29:46 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down

Environment

Release: 1.14.50

Resolution

Having investigated the uploaded diagnostics, we see the below.

 "request": {
          "method": "GET",
          "url": "https://www.google.com/search?q=ynet&rlz=1C1GCEU_enIL955IL955&oq=ynet&aqs=chrome.0.69i59.1232j0j7&sourceid=chrome&ie=UTF-8",
          "httpVersion": "",
          "headers": [
            {
              "name": "Upgrade-Insecure-Requests",
              "value": "1"
            },
            {
              "name": "User-Agent",
              "value": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.54 Safari/537.36"
            },
            {
              "name": "sec-ch-ua",
              "value": "\" Not A;Brand\";v=\"99\", \"Chromium\";v=\"101\", \"Google Chrome\";v=\"101\""
            },
            {
              "name": "sec-ch-ua-mobile",
              "value": "?0"
            },
            {
              "name": "sec-ch-ua-platform",
              "value": "\"Windows\""
            }
          ],
          "queryString": [
            {
              "name": "q",
              "value": "ynet"
            },
            {
              "name": "rlz",
              "value": "1C1GCEU_enIL955IL955"
            },
            {
              "name": "oq",
              "value": "ynet"
            },
            {
              "name": "aqs",
              "value": "chrome.0.69i59.1232j0j7"
            },
            {
              "name": "sourceid",
              "value": "chrome"
            },
            {
              "name": "ie",
              "value": "UTF-8"
            }
          ],
          "cookies": [],
          "headersSize": -1,
          "bodySize": 0
        },
        "response": {
          "status": 0,
          "statusText": "",
          "httpVersion": "",
          "headers": [],
          "cookies": [],
          "content": {
            "size": 0,
            "mimeType": "x-unknown"
          },
          "redirectURL": "",
          "headersSize": -1,
          "bodySize": -1,
          "_transferSize": 0,
          "_error": "net::ERR_ABORTED"
        },
        "serverIPAddress": "",
        "startedDateTime": "2022-05-05T11:40:43.247Z",
        "time": 18.52599997073412,
        "timings": {
          "blocked": 18.52599997073412,
          "dns": -1,
          "ssl": -1,
          "connect": -1,
          "send": 0,
          "wait": 0,
          "receive": 0,
          "_blocked_queueing": -1
        }
      },

 

        "request": {
          "method": "GET",
          "url": "https://www.google.com/search?q=ynet&rlz=1C1GCEU_enIL955IL955&oq=ynet&aqs=chrome.0.69i59.1232j0j7&sourceid=chrome&ie=UTF-8",
          "httpVersion": "",
          "headers": [
            {
              "name": "Upgrade-Insecure-Requests",
              "value": "1"
            },
            {
              "name": "User-Agent",
              "value": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/101.0.4951.54 Safari/537.36"
            },
            {
              "name": "sec-ch-ua",
              "value": "\" Not A;Brand\";v=\"99\", \"Chromium\";v=\"101\", \"Google Chrome\";v=\"101\""
            },
            {
              "name": "sec-ch-ua-mobile",
              "value": "?0"
            },
            {
              "name": "sec-ch-ua-platform",
              "value": "\"Windows\""
            }
          ],
          "queryString": [
            {
              "name": "q",
              "value": "ynet"
            },
            {
              "name": "rlz",
              "value": "1C1GCEU_enIL955IL955"
            },
            {
              "name": "oq",
              "value": "ynet"
            },
            {
              "name": "aqs",
              "value": "chrome.0.69i59.1232j0j7"
            },
            {
              "name": "sourceid",
              "value": "chrome"
            },
            {
              "name": "ie",
              "value": "UTF-8"
            }
          ],
          "cookies": [],
          "headersSize": -1,
          "bodySize": 0
        },
        "response": {
          "status": 0,
          "statusText": "",
          "httpVersion": "",
          "headers": [],
          "cookies": [],
          "content": {
            "size": 0,
            "mimeType": "x-unknown"
          },
          "redirectURL": "",
          "headersSize": -1,
          "bodySize": -1,
          "_transferSize": 0,
          "_error": "net::ERR_EMPTY_RESPONSE"
        },
        "serverIPAddress": "",
        "startedDateTime": "2022-05-05T11:41:52.837Z",
        "time": 5.57700009085238,
        "timings": {
          "blocked": 5.57700009085238,
          "dns": -1,
          "ssl": -1,
          "connect": -1,
          "send": 0,
          "wait": 0,
          "receive": 0,
          "_blocked_queueing": -1

We see empty responses, for the traffic data. Investigating the fireglass_monit.log, we see the below.

May  5 09:20:34 fgproxy1-new :34.307Z -new.toto.org.il AS_WATCHDOG[67667]:[ERROR]: Error: read ECONNRESET
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:ParseCategorizationResult:387] [FGERROR:LOOKUP_PARSE_CATEGORIES_ERROR] session_key: {"SessionKey":{"ClientIp":"192.168.2.176","requestId":"7912362","raw_url":"https://settings.data.microsoft.com:443/","proxy_txn_id":"4191158","isBrowser":true,"organizationName":"Unauthenticated","organizationId":"unauth-000000","destUrl":"https://settings.data.microsoft.com/","mainUrl":"https://settings.data.microsoft.com/","username":""},"isFgLogObject":true} Lookup category status not OK: -4006 --  [2022-05-05T09:20:45.798593Z] 
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:GinAdapter::LookupImpl:471] [FGERROR:LOOKUP_CLASSIFICATION_CATEGORIES_ERROR] session_key: {"SessionKey":{"ClientIp":"192.168.2.176","requestId":"7912362","raw_url":"https://settings.data.microsoft.com:443/","proxy_txn_id":"4191158","isBrowser":true,"organizationName":"Unauthenticated","organizationId":"unauth-000000","destUrl":"https://settings.data.microsoft.com/","mainUrl":"https://settings.data.microsoft.com/","username":""},"isFgLogObject":true} Failed to parse categorization result --  [2022-05-05T09:20:45.798638Z] 
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:URL::URL:21] [FGERROR:GIN_INVALID_URL] Invalid URL:https://settings.data.microsoft.com/ --  [2022-05-05T09:20:45.798672Z] 
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:AsyncHandler:52] [FGERROR:EXCEPTION_DURING_GIN_REQUEST] Error for request:  - {"categorization_status":-4006,"error":"Failed to classify https://settings.data.microsoft.com/","error_code":2,"serial_number":"1009657786","session_key_for_log":"{\"SessionKey\":{\"ClientIp\":\"192.168.2.176\",\"requestId\":\"7912362\",\"raw_url\":\"https://settings.data.microsoft.com:443/\",\"proxy_txn_id\":\"4191158\",\"isBrowser\":true,\"organizationName\":\"Unauthenticated\",\"organizationId\":\"unauth-000000\",\"destUrl\":\"https://settings.data.microsoft.com/\",\"mainUrl\":\"https://settings.data.microsoft.com/\",\"username\":\"\"},\"isFgLogObject\":true}"} --  [2022-05-05T09:20:45.798761Z] 
May  5 09:20:45 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651742445800] [a_s_worker_1[49]::GinClient.js:284] [FGERROR:GIN_CLIENT_UNABLE_TO_CLASSIFY] Unable to classify url: https://settings.data.microsoft.com/*** err: URL categorization failed. <ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >
May  5 09:20:45 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651742445800] [a_s_worker_1[49]::UrlFilteringBusinessLayer.js:161] [FGERROR:URL_FILTERING_CLASSIFY_URL_FAILED] Client classifyUrl failed, error: URL categorization failed. <ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >
May  5 09:20:45 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651742445801] [a_s_worker_1[49]::UrlFilteringMatcher.js:55] [FGERROR:URL_FILTERING_MATCHER_GENERAL_ERROR] Error in url categorization matching. General error: URL categorization failed., errorType: GeneralError, errorCode: undefined, severity: Important <ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:GinAdapter::LookupImpl:480] [FGERROR:LOOKUP_PARSE_RISK_ERROR] session_key: "<ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >" Lookup risk-level status not OK: -4006 --  [2022-05-05T09:20:45.802412Z] 
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:URL::URL:21] [FGERROR:GIN_INVALID_URL] Invalid URL:https://settings.data.microsoft.com/ --  [2022-05-05T09:20:45.802453Z] 
May  5 09:20:45 fgproxy1-new gin_app:  [GIN] [ERROR] [FG:AsyncHandler:52] [FGERROR:EXCEPTION_DURING_GIN_REQUEST] Error for request:  - {"error":"Failed to classify https://settings.data.microsoft.com/","error_code":2,"risk_classification_status":-4006,"serial_number":"1009657786","session_key_for_log":"\"<ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >\""} --  [2022-05-05T09:20:45.802496Z] 
May  5 09:20:45 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651742445803] [a_s_worker_1[49]::GinClient.js:284] [FGERROR:GIN_CLIENT_UNABLE_TO_CLASSIFY] Unable to classify url: https://settings.data.microsoft.com/*** err: URL categorization failed. <ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >
May  5 09:20:45 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651742445803] [a_s_worker_1[49]::RiskLevelMatcher.js:50] [FGERROR:RISK_MATCHER_ERROR] Could not execute risk level matcher. Returning false, error: URL categorization failed. <ClientId:  ClientIp: 192.168.2.176 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 4191158 RequestId: 7912362 Url: https://settings.data.microsoft.com/*** Username: >

May  3 15:17:18 fgproxy1-new localhost a_s_worker_0[44]: [ERROR] [WARN] [1651591038333] [a_s_worker_0[44]::ProfilingPatcher.js:92] [FGERROR:PROFILING_PATCHER_TIMEOUT] [ ProxyContentScannerService.scanContent ] [FINISHED] [TIMEOUT]. Time: 2513 ms 2513185 usec <ClientId:  ClientIp: 192.168.22.11 ProxyTxnId: 3190818 RequestId: 6024525 Url: https://abs-0.twimg.com:443/emoji/v2/svg/1f49a.svg***>
May  3 15:17:31 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [WARN] [1651591051145] [a_s_worker_1[49]::ProfilingPatcher.js:92] [FGERROR:PROFILING_PATCHER_TIMEOUT] [ ProxyContentScannerService.scanContent ] [FINISHED] [TIMEOUT]. Time: 2637 ms 2636979 usec <ClientId:  ClientIp: 192.168.22.11 ProxyTxnId: 3190928 RequestId: 6024732 Url: https://abs-0.twimg.com:443/emoji/v2/svg/1f428.svg***>
May  3 15:17:54 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651591074516] [a_s_worker_1[49]::GinClient.js:284] [FGERROR:GIN_CLIENT_UNABLE_TO_CLASSIFY] Unable to classify url: https://pltrack.bz/*** err: RequestError: Error: ESOCKETTIMEDOUT#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at ClientRequest.<anonymous> (/node_modules/request/request.js:819:16)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at ClientRequest.emit (events.js:208:7)#012    at Socket.emitTimeout (_http_client.js:718:34)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at Socket.emit (events.js:208:7)#012    at Socket._onTimeout (net.js:422:8)#012    at ontimeout (timers.js:498:11)#012    at tryOnTimeout (timers.js:323:5)#012    at Timer.listOnTimeout (timers.js:290:5) <ClientId:  ClientIp: 192.168.55.7 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 3191267 RequestId: 6025389 Url: https://pltrack.bz/*** Username: >
May  3 15:17:54 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651591074516] [a_s_worker_1[49]::UrlFilteringBusinessLayer.js:161] [FGERROR:URL_FILTERING_CLASSIFY_URL_FAILED] Client classifyUrl failed, error: RequestError: Error: ESOCKETTIMEDOUT#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at ClientRequest.<anonymous> (/node_modules/request/request.js:819:16)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at ClientRequest.emit (events.js:208:7)#012    at Socket.emitTimeout (_http_client.js:718:34)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at Socket.emit (events.js:208:7)#012    at Socket._onTimeout (net.js:422:8)#012    at ontimeout (timers.js:498:11)#012    at tryOnTimeout (timers.js:323:5)#012    at Timer.listOnTimeout (timers.js:290:5) <ClientId:  ClientIp: 192.168.55.7 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 3191267 RequestId: 6025389 Url: https://pltrack.bz/*** Username: >
May  3 15:17:54 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651591074516] [a_s_worker_1[49]::UrlFilteringMatcher.js:60] [FGERROR:URL_FILTERING_MATCHER_ERROR] Error in url categorization matching. Error: RequestError: Error: ESOCKETTIMEDOUT#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at ClientRequest.<anonymous> (/node_modules/request/request.js:819:16)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at ClientRequest.emit (events.js:208:7)#012    at Socket.emitTimeout (_http_client.js:718:34)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at Socket.emit (events.js:208:7)#012    at Socket._onTimeout (net.js:422:8)#012    at ontimeout (timers.js:498:11)#012    at tryOnTimeout (timers.js:323:5)#012    at Timer.listOnTimeout (timers.js:290:5) <ClientId:  ClientIp: 192.168.55.7 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 3191267 RequestId: 6025389 Url: https://pltrack.bz/*** Username: >
May  3 15:17:57 fgproxy1-new localhost a_s_worker_1[49]: [ERROR] [1651591077519] [a_s_worker_1[49]::GinClient.js:284] [FGERROR:GIN_CLIENT_UNABLE_TO_CLASSIFY] Unable to classify url: https://pltrack.bz/*** err: RequestError: Error: ESOCKETTIMEDOUT#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at ClientRequest.<anonymous> (/node_modules/request/request.js:819:16)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at ClientRequest.emit (events.js:208:7)#012    at Socket.emitTimeout (_http_client.js:718:34)#012    at Object.onceWrapper (events.js:313:30)#012    at emitNone (events.js:106:13)#012    at Socket.emit (events.js:208:7)#012    at Socket._onTimeout (net.js:422:8)#012    at ontimeout (timers.js:498:11)#012    at tryOnTimeout (timers.js:323:5)#012    at Timer.listOnTimeout (timers.js:290:5) <ClientId:  ClientIp: 192.168.55.7 IsBrowser: true OrganizationId: unauth-000000 OrganizationName: Unauthenticated ProxyTxnId: 3191267 RequestId: 6025389 Url: https://pltrack.bz/*** Username: >
May  3 15:17:5

The GIN errors appear to point to a GeoIP database update failure possibly linked with a known bug, ADAMA-5611. This will be further verified, internally. 


May  5 09:20:59 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:20:59 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:20:59 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:20:59 fgproxy1-new :59.395Z -new.toto.org.il AS_WATCHDOG[67724]:[ERROR]: Error: read ECONNRESET
May  5 09:21:03 fgproxy1-new localhost node[9]: [ERROR] [1651742463396] [proxy_health[9]::ProxyStatsService.js:50] [FGERROR:PROXY_STATS_SERVICE_ERROR_REPORTING_STATS] Could not complete proxy stats reporting. error:  RequestError: Error: read ECONNRESET#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at Request.onRequestError (/node_modules/request/request.js:881:8)#012    at emitOne (events.js:116:13)#012    at ClientRequest.emit (events.js:211:7)#012    at Socket.socketErrorListener (_http_client.js:401:9)#012    at emitOne (events.js:116:13)#012    at Socket.emit (events.js:211:7)#012    at emitErrorNT (internal/streams/destroy.js:66:8)#012    at _combinedTickCallback (internal/process/next_tick.js:139:11)#012    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
May  5 09:21:24 fgproxy1-new gin_app:  [GIN] [FATAL] [FG:ClassificationBusinessLogic::notifyOnEntitlementsReceived:249] ALWAYS <Not Error> Requesting for trusted certificates list --  [2022-05-05T09:21:24.397468Z] 
May  5 09:21:24 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:21:24 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:21:24 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:21:49 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' status succeeded [status=0] -- no output
May  5 09:21:49 fgproxy1-new :49.586Z -new.toto.org.il AS_WATCHDOG[67818]:[ERROR]: Error: read ECONNRESET

May  5 09:27:15 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:27:15 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:27:15 fgproxy1-new :15.790Z -new.toto.org.il AS_WATCHDOG[68453]:[ERROR]: Error: read ECONNRESET
May  5 09:27:24 fgproxy1-new gin_app:  [GIN] [FATAL] [FG:ClassificationBusinessLogic::notifyOnEntitlementsReceived:249] ALWAYS <Not Error> Requesting for trusted certificates list --  [2022-05-05T09:27:24.413728Z] 
May  5 09:27:33 fgproxy1-new localhost node[9]: [ERROR] [1651742853402] [proxy_health[9]::ProxyStatsService.js:50] [FGERROR:PROXY_STATS_SERVICE_ERROR_REPORTING_STATS] Could not complete proxy stats reporting. error:  RequestError: Error: read ECONNRESET#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at Request.onRequestError (/node_modules/request/request.js:881:8)#012    at emitOne (events.js:116:13)#012    at ClientRequest.emit (events.js:211:7)#012    at Socket.socketErrorListener (_http_client.js:401:9)#012    at emitOne (events.js:116:13)#012    at Socket.emit (events.js:211:7)#012    at emitErrorNT (internal/streams/destroy.js:66:8)#012    at _combinedTickCallback (internal/process/next_tick.js:139:11)#012    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
May  5 09:27:40 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:27:40 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:27:40 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:27:40 fgproxy1-new :40.879Z -new.toto.org.il AS_WATCHDOG[68507]:[ERROR]: Error: read ECONNRESET
May  5 09:28:03 fgproxy1-new localhost node[9]: [ERROR] [1651742883402] [proxy_health[9]::ProxyStatsService.js:50] [FGERROR:PROXY_STATS_SERVICE_ERROR_REPORTING_STATS] Could not complete proxy stats reporting. error:  RequestError: Error: read ECONNRESET#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at Request.onRequestError (/node_modules/request/request.js:881:8)#012    at emitOne (events.js:116:13)#012    at ClientRequest.emit (events.js:211:7)#012    at Socket.socketErrorListener (_http_client.js:401:9)#012    at emitOne (events.js:116:13)#012    at Socket.emit (events.js:211:7)#012    at emitErrorNT (internal/streams/destroy.js:66:8)#012    at _combinedTickCallback (internal/process/next_tick.js:139:11)#012    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
May  5 09:28:05 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:28:05 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:28:05 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:28:05 fgproxy1-new :05.979Z -new.toto.org.il AS_WATCHDOG[68553]:[ERROR]: Error: read ECONNRESET
May  5 09:28:24 fgproxy1-new gin_app:  [GIN] [FATAL] [FG:ClassificationBusinessLogic::notifyOnEntitlementsReceived:249] ALWAYS <Not Error> Requesting for trusted certificates list --  [2022-05-05T09:28:24.416747Z] 
May  5 09:28:31 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:28:31 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:28:31 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:28:31 fgproxy1-new :31.076Z -new.toto.org.il AS_WATCHDOG[68604]:[ERROR]: Error: read ECONNRESET
May  5 09:28:33 fgproxy1-new localhost node[9]: [ERROR] [1651742913402] [proxy_health[9]::ProxyStatsService.js:50] [FGERROR:PROXY_STATS_SERVICE_ERROR_REPORTING_STATS] Could not complete proxy stats reporting. error:  RequestError: Error: read ECONNRESET#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at Request.onRequestError (/node_modules/request/request.js:881:8)#012    at emitOne (events.js:116:13)#012    at ClientRequest.emit (events.js:211:7)#012    at Socket.socketErrorListener (_http_client.js:401:9)#012    at emitOne (events.js:116:13)#012    at Socket.emit (events.js:211:7)#012    at emitErrorNT (internal/streams/destroy.js:66:8)#012    at _combinedTickCallback (internal/process/next_tick.js:139:11)#012    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
May  5 09:28:56 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:28:56 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:28:56 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:28:56 fgproxy1-new :56.168Z -new.toto.org.il AS_WATCHDOG[68650]:[ERROR]: Error: read ECONNRESET
May  5 09:29:03 fgproxy1-new localhost node[9]: [ERROR] [1651742943404] [proxy_health[9]::ProxyStatsService.js:50] [FGERROR:PROXY_STATS_SERVICE_ERROR_REPORTING_STATS] Could not complete proxy stats reporting. error:  RequestError: Error: read ECONNRESET#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at Request.onRequestError (/node_modules/request/request.js:881:8)#012    at emitOne (events.js:116:13)#012    at ClientRequest.emit (events.js:211:7)#012    at Socket.socketErrorListener (_http_client.js:401:9)#012    at emitOne (events.js:116:13)#012    at Socket.emit (events.js:211:7)#012    at emitErrorNT (internal/streams/destroy.js:66:8)#012    at _combinedTickCallback (internal/process/next_tick.js:139:11)#012    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
May  5 09:29:21 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:29:21 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:29:21 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down
May  5 09:29:21 fgproxy1-new :21.255Z -new.toto.org.il AS_WATCHDOG[68702]:[ERROR]: Error: read ECONNRESET
May  5 09:29:24 fgproxy1-new gin_app:  [GIN] [FATAL] [FG:ClassificationBusinessLogic::notifyOnEntitlementsReceived:249] ALWAYS <Not Error> Requesting for trusted certificates list --  [2022-05-05T09:29:24.419525Z] 
May  5 09:29:33 fgproxy1-new localhost node[9]: [ERROR] [1651742973403] [proxy_health[9]::ProxyStatsService.js:50] [FGERROR:PROXY_STATS_SERVICE_ERROR_REPORTING_STATS] Could not complete proxy stats reporting. error:  RequestError: Error: read ECONNRESET#012    at new RequestError (/node_modules/request-promise-core/lib/errors.js:14:15)#012    at Request.plumbing.callback (/node_modules/request-promise-core/lib/plumbing.js:87:29)#012    at Request.RP$callback [as _callback] (/node_modules/request-promise-core/lib/plumbing.js:46:31)#012    at self.callback (/node_modules/request/request.js:185:22)#012    at emitOne (events.js:116:13)#012    at Request.emit (events.js:211:7)#012    at Request.onRequestError (/node_modules/request/request.js:881:8)#012    at emitOne (events.js:116:13)#012    at ClientRequest.emit (events.js:211:7)#012    at Socket.socketErrorListener (_http_client.js:401:9)#012    at emitOne (events.js:116:13)#012    at Socket.emit (events.js:211:7)#012    at emitErrorNT (internal/streams/destroy.js:66:8)#012    at _combinedTickCallback (internal/process/next_tick.js:139:11)#012    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
May  5 09:29:46 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' '/opt/fireglass/1.14.50+774/ci_infra/async_services/as_watchdog.sh' failed with exit status (1) -- no output
May  5 09:29:46 fgproxy1-new monit[3305]: 'ASYNC_SERVICES_WATCHDOG' exec: /usr/bin/logger
May  5 09:29:46 fgproxy1-new logger: [FATAL] ASYNC_SERVICES is down

Clearly, we see that the async service went down and stayed down for a considerable period of time. There seems to be a fatal issue with the async_services build, with the ASYNC_SERVICES_WATCHDOG. We see lots and lots of these in the logs.

As the next step, please run the sudo monit summary command, only when the issue happens, on the Proxy gateway, look for the "ASYNC_SERVICES_WATCHDOG" section, and send us the output. See the sample in the snippet below, run from our lab env.

If the status is different than the above and below (see the snippet above and below), it means that the policy component has stopped working.

Resolution

Restarting the traffic server and the async services would resolve this. See the commands below.

sudo fgcli service restart Traffic-Server

sudo fgcli service restart Policy-Service