SAP HANA XSA on-premise "Read timed out (local port # to address 10.xx (xxxxxx)"

[draschke]

Hi,

I do have the issue that if I try to start our js modul it runs at first in a timeout.

Read timed out (local port # to address # (#), remote port # to address # (#))

I need always two executes to get the js modul to run. The first time of the execute runs each time in a time out (after a couple of minutes). The second execute takes also a lot of minutes but is starting after that. This all together needs almost between 10 until 15 minutes... 😞 . It's a small project.

This issue was not from the beginning of this project. It came up overnight. I'm not beware that I was changing any properties of this project or any important properties of the js modul.

We had this same behavior also in an other project a couple of months ago but wasn't able to find out what the reason is. In this project is the issue gone.

Was playing with INCOMING_CONNECTION_TIMEOUT, but didn't work for me

https://help.sap.com/viewer/4505d0bdaf4948449b7f7379d24d0f0d/2.0.01/en-US/0aac697f0cf7444193ed5eb0fc...

Could anyone help us?

[thomas_jung]

I've also experienced this after working for many hours on a system. I find that a restart of the di-core service will return the running operation to normal performance.

[draschke]

Tried restarting di-core and after that webide, but with no success.

Two days ago we were starting also the whole system, so that each service should be restarted already.

I was also looking for log files, but couldn't find any hint for this issue. Please let me know, if you have any further ideas, to get this really annoying issue fixed.

Thanks a lot!

[thomas_jung]

Another suggestion would be to run the service. After the wait time hit the stop button from the Web IDE run console. This should delete the app (same as doing the xs delete command) but also clean up any metadata about the running service in di-core. The next run won't be a delta run but a full. However after that you should get delta runs again.

You could also be timing out during the deploy due to poor performance on the underlying file system. If you have a recent XSA Runtime version, run XSA diagnose from Linux as the sidadm user. This will test the throughput on the file system which highly impacts the build/deploy/run commands.

[draschke]

The first suggestion doesn't work for me. Did it so often, but there is no difference. The behavior is after that still the same.

For the second suggestion I will ask our admin if he can look for it.

Thanks for your fast reply!

[draschke]

He doesn't know what you mean with "run XSA diagnose from Linux". Is there an explicit cmd which we can use for this diagnosis?

[thomas_jung]

Yes the command is:
XSA diagnose

That log file has much more details about the checks which were performed.

All the XSA command options:

[draschke]

Thanks a lot!

We will check for it, but at first we do have to update our XSA runtime (new feature came with build 1.0.82).

As soon we have done it, I will give you my feedback.

[draschke]

Besides our admin found something within the xscontroller, which seems that it has something to do with the 'component-registry-db' service. At this time (08:46) I was reproducing this error.

[2018-04-12 08:46:37:204]-[Controller.App]-[log]-[UserDummy]-[client_262a::push - 97712]: Updated app 'dummy-js' [Org 'orgname', Space 'DEV'] (state: STARTED) with entity {'name':'dummy-js', 'memory':20480, 'instances':1, 'disk_quota':-1, 'space_guid':'d531a07b-f971-4b06-83da-36f9796a1a57', 'state':'STARTED', 'buildpack':urlDummy/git-server/2f/66/af/SYSTEM/nodejsappcontroller-buildpack-project', 'health_check_type':'port', 'start_priority':0}.
[2018-04-12 08:46:39:123]-[Controller.Balancer]-[warning]-[controller]-[balancing - 11552]: Number of running instances for app 'component-registry-db' [Org 'orgname', Space 'SAP'] is 0 but should be 1. Trying to adapt number of running instances...
[2018-04-12 08:46:39:130]-[Controller.App]-[log]-[controller]-[balancing - 11552]: Cleared instance [state CRASHED, index 4] of droplet [id 6] of app 'component-registry-db' [Org 'orgname', Space 'SAP'] at [dummy:Port, pid 34053].
[2018-04-12 08:46:39:309]-[Controller.App]-[log]-[controller]-[balancing - 11552]: Starting instance [state STARTING, index 4] of droplet [id 6] of app 'component-registry-db' [Org 'orgname', Space 'SAP'] at [dummy:Port].
[2018-04-12 08:46:42:520]-[Controller.App]-[log]-[UserDummy]-[client_262a::push - 97717]: Updated files for app 'dummy-js' [Org 'orgname', Space 'DEV'] to BlobSet '79c241b3-25f3-43d7-93b0-e75e879bd1c5'
[2018-04-12 08:46:55:929]-[Controller.Droplet]-[log]-[UserDummy]-[client_262a::push. restageInfo - 97722]: Created droplet with id 38 of app 'dummy-js' [Org 'orgname', Space 'DEV'] created by buildpack urlDummy/git-server/2f/66/af/SYSTEM/nodejsappcontroller-buildpack-project' with entity {'app_guid':'e574a9ff-7800-48bc-863f-f1f0b036296d', 'buildpack':urlDummy/git-server/2f/66/af/SYSTEM/nodejsappcontroller-buildpack-project', 'state':'STAGING'}
[2018-04-12 08:46:55:934]-[Controller.Job]-[log]-[UserDummy]-[client_262a::push. restageInfo - 97722]: Started job "Staging app 'dummy-js' [Org 'orgname', Space 'DEV']" with id '097a5693-6a96-47a0-874d-91ed5ea26893'  in space 'DEV' [org: 'orgname'] of user 'UserDummy'.
[2018-04-12 08:46:55:948]-[Controller.Droplet]-[log]-[UserDummy]-[client_262a::push. restageInfo - 97722]: Staging Droplet with id 38 of app dummy-js' [Org 'orgname', Space 'DEV'] created by buildpack urlDummy/git-server/2f/66/af/SYSTEM/nodejsappcontroller-buildpack-project'.
[2018-04-12 08:47:03:828]-[Stager]-[log]-[UserDummy]-[client_262a::push. restageInfo - 97722]: Extracted files for application 'dummy-js' (files: 25,969, size: 330,919,798 bytes, duration: 6,921 ms, throughput: 45.60 MB/s)

[draschke]

I was restarting this service again, but still the same. May be there is more to do as a simple restart!?

[thomas_jung]

I would look at the logs of component-registry-db itself to try and see why its failing.

[draschke]

Forgot to say, I've done it already.

The error comes from a service which I've never created.

ERR    Error: service lcm-view-grantor not found

In my opinion I would assume that this error should be than a global issue and also affect the other projects. But only this one ís affected.

Connected, dumping recent logs for app "component-registry-db"
12.04.18 13:41:18.085 [APP/6-7] OUT    @sap/hdi-deploy, version 3.1.2, server version 2.00.023.00.1513691289 (2.0.23.0), node version 6.12.2
12.04.18 13:41:18.108 [APP/6-7] OUT    Collecting files...
12.04.18 13:41:18.119 [APP/6-7] OUT    Collecting files... ok (0s 11ms)
12.04.18 13:41:18.120 [APP/6-7] OUT    10 directories collected
12.04.18 13:41:18.120 [APP/6-7] OUT    109 files collected
12.04.18 13:41:18.120 [APP/6-7] OUT    0 reusable modules collected
12.04.18 13:41:18.124 [APP/6-7] OUT    Processing grants files...
12.04.18 13:41:18.125 [APP/6-7] OUT     Processing "cfg/grants.hdbsynonymgrantor"...
12.04.18 13:41:18.127 [APP/6-7] ERR    Error: service lcm-view-grantor not found; either the service definition does not exist or it is not tagged with the tag "hana"
12.04.18 13:41:18.129 [APP/6-7] OUT    (0s 366ms)
12.04.18 13:41:18.129 [APP/6-7] OUT
12.04.18 13:41:39.175 [API] ERR   Number of running instances for app 'component-registry-db' [Org 'orgname', Space 'SAP'] is 0 but should be 1. Trying to adapt number of running instances...
12.04.18 13:41:39.184 [API] OUT   Cleared instance [state CRASHED, index 8] of droplet [id 6] of app 'component-registry-db' [Org 'orgname', Space 'SAP'] at [:xxx, pid xxx].
12.04.18 13:41:39.349 [API] OUT   Starting instance [state STARTING, index 8] of droplet [id 6] of app 'component-registry-db' [Org 'orgname', Space 'SAP'] at [:xxx].
12.04.18 13:41:48.079 [APP/6-8] OUT    @sap/hdi-deploy, version 3.1.2, server version 2.00.023.00.1513691289 (2.0.23.0), node version 6.12.2
12.04.18 13:41:48.125 [APP/6-8] OUT    Collecting files...
12.04.18 13:41:48.136 [APP/6-8] OUT    Collecting files... ok (0s 11ms)
12.04.18 13:41:48.137 [APP/6-8] OUT    10 directories collected
12.04.18 13:41:48.137 [APP/6-8] OUT    109 files collected
12.04.18 13:41:48.137 [APP/6-8] OUT    0 reusable modules collected
12.04.18 13:41:48.141 [APP/6-8] OUT    Processing grants files...
12.04.18 13:41:48.142 [APP/6-8] OUT     Processing "cfg/grants.hdbsynonymgrantor"...
12.04.18 13:41:48.144 [APP/6-8] ERR    Error: service lcm-view-grantor not found; either the service definition does not exist or it is not tagged with the tag "hana"
12.04.18 13:41:48.148 [APP/6-8] OUT    (0s 365ms)
12.04.18 13:41:48.148 [APP/6-8] OUT
<br>

[thomas_jung]

The component-registry-db seems like a problem but I'm also not sure its related to the long runtimes. Its probably just that the controller is periodically trying to restart the application that fails. But the fact that it is failing is in itself a problem I would think. I see some old notes around lcm-view-grantor but they tend cause problems during the update. I checked my local system and lcm-view-grantor doesn't exist as a service there. It might be something we've gotten rid of. One more reason to try an update of XSA RT as it might also fix this component-registry-db error.

[draschke]

We have upgraded our WebIDE to SPS3. The issue is still there, nothing has changed. (Even the component-registry-db is further crashing and throws the same error.)

The cmd xs diagnose says it is all ok. It seems like I've to open an ticket.

[draschke]

Ok, nothing of this points solved my problem.

Tried:

- Update to SPS 03 --> same issue

- no hint within the logs or XSA diagnose

- Cloning to different space and even more a different system --> same issue

- Exporting, Importing with a different namespace --> same issue

- exchanged the server logic by default server logic (node.js) --> same issue

The interesting point was that we saw the same issue "Read timed out (local port # to address 10.xx (xxxxxx)", while we were updating the system to xsa runtime 1.0.82. It faild, so we had to patch our system to 1.0.83.

My hope that the issue would be away with the new patch did not come true. After that still the same.

In the end I had to rebuild the project manually step by step. This solved my issue. But I was not able to find out what the reason was.

[draschke]

After three days working without any trouble the issue came back again. Now I was opening a incident.