ELK - Something goes wrong in recordRequest #1504
Description
Issue seen in latest tag v2.0.1.e_impl and please have a check. logs are filled with below error messages.
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530256164 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530256164 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 104271383 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 124251705 success *************************
message {"notification-proxy-1-0:alarm-event-notification":{"alarm-event-sequence-number":353988,"timestamp":"2025-10-16T22:51:06+00:00","resource":"/core-model-1-4:network-control-domain=live/control-construct=325270496/logical-termination-point=LTP-MWPS-TTP-3-1","alarm-type-id":"alarm-types:ALARM_TYPE_ID_TYPE_IFPORT_OBJ","alarm-type-qualifier":"MW_LOF/631-110-3-1","problem-severity":"critical"}} successfully received from topic: device_alarm_notifications and partition: 0
message {"notification-proxy-1-0:alarm-event-notification":{"alarm-event-sequence-number":353990,"timestamp":"2025-10-16T22:52:49+00:00","resource":"/core-model-1-4:network-control-domain=live/control-construct=325270496/logical-termination-point=LTP-MWPS-TTP-3-2","alarm-type-id":"alarm-types:ALARM_TYPE_ID_TYPE_IFPORT_OBJ","alarm-type-qualifier":"MW_LOF/631-110-3-2","problem-severity":"cleared"}} successfully received from topic: device_alarm_notifications and partition: 0
message {"notification-proxy-1-0:alarm-event-notification":{"alarm-event-sequence-number":353989,"timestamp":"2025-10-16T22:52:23+00:00","resource":"/core-model-1-4:network-control-domain=live/control-construct=325270496/logical-termination-point=LTP-MWPS-TTP-3-2","alarm-type-id":"alarm-types:ALARM_TYPE_ID_TYPE_IFPORT_OBJ","alarm-type-qualifier":"MW_LOF/631-110-3-2","problem-severity":"critical"}} successfully received from topic: device_alarm_notifications and partition: 0
message {"notification-proxy-1-0:alarm-event-notification":{"alarm-event-sequence-number":353991,"timestamp":"2025-10-16T22:52:49+00:00","resource":"/core-model-1-4:network-control-domain=live/control-construct=325270496/logical-termination-point=LTP-MWPS-TTP-3-1","alarm-type-id":"alarm-types:ALARM_TYPE_ID_TYPE_IFPORT_OBJ","alarm-type-qualifier":"MW_LOF/631-110-3-1","problem-severity":"cleared"}} successfully received from topic: device_alarm_notifications and partition: 0
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 529270099 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530255615 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530256164 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 325255136 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530255615 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530256164 success *************************
JSON Object is null ************************
JSON Object is null ************************
JSON Object is null ************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530253695 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530253695 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 325270496 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 325270496 success *************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 325270496 success *************************
JSON Object is null ************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 325270496 success *************************
message {"notification-proxy-1-0:alarm-event-notification":{"alarm-event-sequence-number":3362861,"timestamp":"2025-10-17T14:54:00+02:00","resource":"/core-model-1-4:network-control-domain=live/control-construct=530550883B/logical-termination-point=RF-819.1.1","alarm-type-id":"alarms-ext-ericsson-ml6300:ALARM_TYPE_ID_rfInputThreshold","alarm-type-qualifier":"","problem-severity":"cleared"}} successfully received from topic: device_alarm_notifications and partition: 0
[17.10.2025 12:54.04.053] [LOG]
callback : POST http://10.20.64.41:3033/v1/record-service-request header :{"user":"MicroWaveDeviceInventory","originator":"MicroWaveDeviceInventory","x-correlator":"4B4aa0d0-e81B-1F0E-44ED-0daAC8bDB8eB","trace-indicator":"1","customer-journey":"unknown","operation-key":"Operation key not yet provided.","Content-Type":"application/json"}body :{"x-correlator":"dadf19CC-CE19-8Da4-a67A-2DD7B6DD2AcB","trace-indicator":"1.1.1.1.2","user":"MicroWaveDeviceInventory","originator":"RegistryOffice","application-name":"MicroWaveDeviceInventory","release-number":"2.0.1","operation-name":"/v1/embed-yourself","response-code":204,"timestamp":"2025-10-17T12:53:54+00:00"}response code:204
[17.10.2025 12:54.04.054] [LOG] Iteration 59 for the node 202253731
JSON Object is null ************************
*************************************** WRITE DEVICE-METADATA TO ES SUCCESS **************************************************
******************* partial update for 530550883B success *************************
[17.10.2025 12:54.04.064] [LOG] Iteration 60 for the node 326252125
[17.10.2025 12:54.04.075] [LOG] Iteration 61 for the node 124251418
[17.10.2025 12:54.04.088] [LOG] Iteration 62 for the node 417277112
[17.10.2025 12:54.04.098] [LOG] Iteration 63 for the node 530255409
[12:54:04.125] INFO (1): Mountname=101259715 queued update. Queue size now: 1
[12:54:04.126] INFO (1): Mountname=530255615 queued update. Queue size now: 1
[12:54:04.126] INFO (1): Mountname=530255615 queued update. Queue size now: 2
[12:54:04.127] INFO (1): Mountname=202251987 queued update. Queue size now: 1
[12:54:04.134] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.134] INFO (1): Mountname=101259715 processed update. Duration=0.009s. Queue size after process: 0
[12:54:04.135] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.135] INFO (1): Mountname=530255615 processed update. Duration=0.009s. Queue size after process: 1
[12:54:04.135] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.135] INFO (1): Mountname=530255615 processed update. Duration=0.009s. Queue size after process: 0
[12:54:04.138] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.138] INFO (1): Mountname=202251987 processed update. Duration=0.011s. Queue size after process: 0
[12:54:04.484] INFO (1): Mountname=306252110 queued update. Queue size now: 1
[12:54:04.484] INFO (1): Mountname=306252110 queued update. Queue size now: 2
[12:54:04.485] INFO (1): Mountname=306252110 queued update. Queue size now: 3
[12:54:04.485] INFO (1): Mountname=306252110 queued update. Queue size now: 4
[12:54:04.485] INFO (1): Mountname=325253176 queued update. Queue size now: 1
[12:54:04.486] INFO (1): Mountname=325253176 queued update. Queue size now: 2
[12:54:04.486] INFO (1): Mountname=427550361B queued update. Queue size now: 1
[12:54:04.486] INFO (1): Mountname=427550361B queued update. Queue size now: 2
[12:54:04.494] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.494] INFO (1): Mountname=306252110 processed update. Duration=0.01s. Queue size after process: 0
[12:54:04.495] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.495] INFO (1): Mountname=427550361B processed update. Duration=0.009s. Queue size after process: 1
[12:54:04.495] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.495] INFO (1): Mountname=325253176 processed update. Duration=0.01s. Queue size after process: 0
[12:54:04.496] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.496] INFO (1): Mountname=325253176 processed update. Duration=0.01s. Queue size after process: 1
[12:54:04.497] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.497] INFO (1): Mountname=306252110 processed update. Duration=0.012s. Queue size after process: 3
[12:54:04.497] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.497] INFO (1): Mountname=427550361B processed update. Duration=0.011s. Queue size after process: 0
[12:54:04.498] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.498] INFO (1): Mountname=306252110 processed update. Duration=0.014s. Queue size after process: 1
[12:54:04.500] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.501] INFO (1): Mountname=306252110 processed update. Duration=0.016s. Queue size after process: 2
[12:54:04.600] INFO (1): Mountname=306277282 queued update. Queue size now: 1
[12:54:04.600] INFO (1): Mountname=418552034B queued update. Queue size now: 1
[12:54:04.601] INFO (1): Mountname=530550883B queued update. Queue size now: 1
[12:54:04.606] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.607] INFO (1): Mountname=306277282 processed update. Duration=0.007s. Queue size after process: 0
[12:54:04.607] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.607] INFO (1): Mountname=530550883B processed update. Duration=0.006s. Queue size after process: 0
[12:54:04.609] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.609] INFO (1): Mountname=418552034B processed update. Duration=0.009s. Queue size after process: 0
[12:54:04.701] INFO (1): Mountname=529270176 queued update. Queue size now: 1
[12:54:04.702] INFO (1): Mountname=530256164 queued update. Queue size now: 1
[12:54:04.702] INFO (1): Mountname=530256164 queued update. Queue size now: 2
[12:54:04.703] INFO (1): Mountname=325253176 queued update. Queue size now: 1
[12:54:04.706] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.706] INFO (1): Mountname=325253176 processed update. Duration=0.003s. Queue size after process: 0
[12:54:04.707] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.707] INFO (1): Mountname=529270176 processed update. Duration=0.006s. Queue size after process: 0
[12:54:04.708] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.708] INFO (1): Mountname=530256164 processed update. Duration=0.006s. Queue size after process: 1
[12:54:04.709] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.709] INFO (1): Mountname=530256164 processed update. Duration=0.007s. Queue size after process: 0
[12:54:04.804] INFO (1): Mountname=325253176 queued update. Queue size now: 1
[12:54:04.805] INFO (1): Mountname=325253176 queued update. Queue size now: 2
[12:54:04.806] INFO (1): Mountname=325253176 queued update. Queue size now: 3
[12:54:04.806] INFO (1): Mountname=530270895 queued update. Queue size now: 1
[12:54:04.806] INFO (1): Mountname=530270895 queued update. Queue size now: 2
[12:54:04.810] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.810] INFO (1): Mountname=325253176 processed update. Duration=0.006s. Queue size after process: 0
[12:54:04.811] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.811] INFO (1): Mountname=325253176 processed update. Duration=0.005s. Queue size after process: 2
[12:54:04.813] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.813] INFO (1): Mountname=530270895 processed update. Duration=0.007s. Queue size after process: 0
[12:54:04.814] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.814] INFO (1): Mountname=325253176 processed update. Duration=0.009s. Queue size after process: 1
[12:54:04.815] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:04.815] INFO (1): Mountname=530270895 processed update. Duration=0.009s. Queue size after process: 1
[12:54:05.013] INFO (1): Mountname=427252978 queued update. Queue size now: 1
[12:54:05.013] INFO (1): Mountname=529251919 queued update. Queue size now: 1
[12:54:05.014] INFO (1): Mountname=124252319 queued update. Queue size now: 1
[12:54:05.014] INFO (1): Mountname=529271215 queued update. Queue size now: 1
[12:54:05.015] INFO (1): Mountname=529271215 queued update. Queue size now: 2
[12:54:05.022] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.022] INFO (1): Mountname=427252978 processed update. Duration=0.009s. Queue size after process: 0
[12:54:05.027] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.027] INFO (1): Mountname=529271215 processed update. Duration=0.012s. Queue size after process: 1
[12:54:05.028] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.028] INFO (1): Mountname=529251919 processed update. Duration=0.015s. Queue size after process: 0
[12:54:05.030] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.030] INFO (1): Mountname=529271215 processed update. Duration=0.016s. Queue size after process: 0
[12:54:05.031] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.031] INFO (1): Mountname=124252319 processed update. Duration=0.017s. Queue size after process: 0
[12:54:05.128] INFO (1): Mountname=101557746A queued update. Queue size now: 1
[12:54:05.129] INFO (1): Mountname=101557746A queued update. Queue size now: 2
[12:54:05.129] INFO (1): Mountname=530550882B queued update. Queue size now: 1
[12:54:05.130] INFO (1): Mountname=529270176 queued update. Queue size now: 1
[12:54:05.130] INFO (1): Mountname=529270395 queued update. Queue size now: 1
[12:54:05.130] INFO (1): Mountname=325270496 queued update. Queue size now: 1
[12:54:05.131] INFO (1): Mountname=325270496 queued update. Queue size now: 2
[12:54:05.135] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.135] INFO (1): Mountname=529270395 processed update. Duration=0.005s. Queue size after process: 0
[12:54:05.136] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.136] INFO (1): Mountname=325270496 processed update. Duration=0.005s. Queue size after process: 1
[12:54:05.136] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.136] INFO (1): Mountname=101557746A processed update. Duration=0.007s. Queue size after process: 1
[12:54:05.137] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.137] INFO (1): Mountname=530550882B processed update. Duration=0.008s. Queue size after process: 0
[12:54:05.140] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.140] INFO (1): Mountname=101557746A processed update. Duration=0.012s. Queue size after process: 0
[12:54:05.140] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.141] INFO (1): Mountname=529270176 processed update. Duration=0.01s. Queue size after process: 0
[12:54:05.141] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.141] INFO (1): Mountname=325270496 processed update. Duration=0.011s. Queue size after process: 0
[12:54:05.302] INFO (1): Mountname=529270395 queued update. Queue size now: 1
[12:54:05.302] INFO (1): Mountname=529270395 queued update. Queue size now: 2
[12:54:05.303] INFO (1): Mountname=530550883B queued update. Queue size now: 1
[12:54:05.303] INFO (1): Mountname=437251596 queued update. Queue size now: 1
[12:54:05.303] INFO (1): Mountname=437251596 queued update. Queue size now: 2
[12:54:05.304] INFO (1): Mountname=124252319 queued update. Queue size now: 1
[12:54:05.304] INFO (1): Mountname=124252319 queued update. Queue size now: 2
[12:54:05.307] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.308] INFO (1): Mountname=529270395 processed update. Duration=0.006s. Queue size after process: 1
[12:54:05.316] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.318] INFO (1): Mountname=437251596 processed update. Duration=0.015s. Queue size after process: 1
[12:54:05.319] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.319] INFO (1): Mountname=437251596 processed update. Duration=0.016s. Queue size after process: 0
[12:54:05.320] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.320] INFO (1): Mountname=124252319 processed update. Duration=0.016s. Queue size after process: 0
[12:54:05.321] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.321] INFO (1): Mountname=530550883B processed update. Duration=0.018s. Queue size after process: 0
[12:54:05.321] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.322] INFO (1): Mountname=529270395 processed update. Duration=0.02s. Queue size after process: 0
[12:54:05.332] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.332] INFO (1): Mountname=124252319 processed update. Duration=0.028s. Queue size after process: 1
[12:54:05.467] INFO (1): Mountname=530255615 queued update. Queue size now: 1
[12:54:05.467] INFO (1): Mountname=530255615 queued update. Queue size now: 2
[12:54:05.468] INFO (1): Mountname=202251987 queued update. Queue size now: 1
[12:54:05.468] INFO (1): Mountname=427550361B queued update. Queue size now: 1
[12:54:05.469] INFO (1): Mountname=427550361B queued update. Queue size now: 2
[12:54:05.481] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.482] INFO (1): Mountname=530255615 processed update. Duration=0.014s. Queue size after process: 0
[12:54:05.482] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.482] INFO (1): Mountname=202251987 processed update. Duration=0.014s. Queue size after process: 0
[12:54:05.483] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.483] INFO (1): Mountname=427550361B processed update. Duration=0.014s. Queue size after process: 1
[12:54:05.484] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.484] INFO (1): Mountname=530255615 processed update. Duration=0.017s. Queue size after process: 1
[12:54:05.485] ERROR (1): ELK - Something goes wrong in recordRequest, check the DEBUG level
[12:54:05.485] INFO (1): Mountname=427550361B processed update. Duration=0.017s. Queue size after process: 0
^C
[root@mwappserver2 database]#