Trouble using a surface from speckle server to run a script with hops

jan-casas · 3 September 2023 11:25

Hi! I’m having trouble using a surface from speckle server to run a script with hops. I want the receive component and the gh script to be in the same file so I can use them with rhino. Compute in a web app. At the moment i am testing with hops in local. Does anyone know how to fix this?

Version: speckle 2.15 and 2.16.0-wip3, rhino7
Objective: bake specific wall type using hops (in the near future using rhino.compute) using the input base curve from speckle server and send it again to speckle server.
Issue: this error indicates that an HTTP POST request to the “/grasshopper” endpoint resulted in a 500 Internal Server Error, and the request was canceled because it exceeded the configured timeout of 100 seconds. The error stack trace suggests that the underlying issue may be related to socket communication or I/O operations.
While using the recive sync component in the script (1) the time of response is less than 3 secs .
Example: the folder structure is (1) construction script (gh script and receive speckle component), (2) hops function (it points to 1.)

wall-test.gh (36.9 KB)

rhino. Compute: logging info

[13:04:50 INF] Rhino compute started at 03/09/2023 13:04:50
[13:04:50 INF] Initiliazing reverse proxy at 03/09/2023 13:04:50
[13:04:50 INF] Spawn children at startup is set to True
[13:04:50 INF] Now listening on: http://localhost:6500
[13:04:50 INF] Application started. Press Ctrl+C to shut down.
[13:04:50 INF] Hosting environment: Production
[13:04:50 INF] Content root path: C:\Users\casas\AppData\Roaming\McNeel\Rhinoceros\packages\7.0\Hops\0.16.0\rhino.compute
CG  [13:04:54 INF] Child process started at 03/09/2023 13:04:54
CG  [13:04:55 INF] Configuration Result:
[Success] Name compute.geometry
[Success] DisplayName rhino.compute
[Success] Description rhino.compute
[Success] ServiceName compute.geometry
CG  [13:04:55 INF] Topshelf v4.1.0.172, .NET Framework v4.0.30319.42000
CG  [13:04:55 INF] Compute 1.0.0.0, Rhino 7.32.23221.10241
CG  [13:04:55 INF] Launching RhinoCore library as casas
CG 6001 [13:04:59 INF] (1/2) Loading grasshopper
[13:05:03 INF] Initialized logger inside GrasshopperGrasshopper7/2.16.0-wip3/2.16.0.11724 for user ##########. Path info C:\Users\casas\AppData\Roaming C:\Users\casas\AppData\Roaming.
[13:05:03 INF] Setup was already initialized
[13:05:03 DBG] Starting execution of http request to https://analytics.speckle.systems/engage#profile-union
[13:05:04 INF] Execution of http request to https://analytics.speckle.systems//engage succeeded with OK after 0.3714239 seconds and 0 retries
[13:05:08 INF] (2/2) Loading compute plug-ins
CG 6001 [13:05:09 INF] The compute.geometry service is now running, press Control+C to exit.
[13:05:11 INF] Initializing Kit Manager in C:\Users\casas\AppData\Roaming\Speckle\Kits
[13:05:11 INF] Converter ConverterRhinoGh successfully loaded from C:\Users\casas\AppData\Roaming\Speckle\Kits\Objects\Objects.Converter.Grasshopper7.dll
[13:05:12 INF] ::1 - [2023-09-03T13:05:12.1310698+02:00] "POST /io HTTP/1.1" 200 -
[13:05:12 INF] HTTP POST /io responded 200 in 15323.6778 ms
[13:05:28 DBG] Using cached definition
Headless run with doc 'Untitled'
    with template: 'No template'
    with units: Millimeters
Fetching headless doc 'Untitled'
    with template: 'No template'
    Model units:Millimeters
[13:05:28 INF] Pinging 1.1.1.1
[13:05:28 INF] Pinging 1.1.1.1
[13:05:28 INF] Pinging 1.1.1.1
[13:05:28 DBG] Starting execution of graphql request to get StreamData
[13:05:28 DBG] Starting execution of graphql request to get StreamData
[13:05:28 DBG] Starting execution of graphql request to get StreamData
[13:05:29 DBG] Starting execution of http request to https://speckle.xyz/graphql
[13:05:29 DBG] Starting execution of http request to https://speckle.xyz/graphql
[13:05:29 DBG] Starting execution of http request to https://speckle.xyz/graphql
[13:05:29 INF] Execution of http request to https://speckle.xyz//graphql succeeded with OK after 0.293101 seconds and 0 retries
[13:05:29 INF] Execution of http request to https://speckle.xyz//graphql succeeded with OK after 0.2962249 seconds and 0 retries
[13:05:29 INF] Execution of http request to https://speckle.xyz//graphql succeeded with OK after 0.2945886 seconds and 0 retries
[13:05:29 INF] Execution of graphql request to get StreamData succeeded after 0.4680434 seconds
[13:05:29 INF] Execution of graphql request to get StreamData succeeded after 0.472415 seconds
[13:05:29 INF] Execution of graphql request to get StreamData succeeded after 0.4763429 seconds
[13:05:29 INF] Initializing a new Remote Transport for https://speckle.xyz
[13:05:29 DBG] Starting execution of graphql request to get StreamData
[13:05:29 DBG] Starting execution of http request to https://speckle.xyz/graphql
[13:05:29 INF] Execution of http request to https://speckle.xyz//graphql succeeded with OK after 0.2248122 seconds and 0 retries
[13:05:29 INF] Execution of graphql request to get StreamData succeeded after 0.2548389 seconds
[13:05:29 DBG] Starting execution of http request to https://analytics.speckle.systems/track?ip=1
[13:05:29 INF] Starting receive b485d25434b793562aa472c3b444c412 from transports LC / R
[13:05:30 INF] Finished receiving b485d25434b793562aa472c3b444c412 from LC in 0.21221 seconds
[13:05:30 DBG] Starting execution of graphql request to get Dictionary`2
[13:05:30 DBG] Starting execution of http request to https://speckle.xyz/graphql
[13:05:30 INF] Execution of http request to https://analytics.speckle.systems//track?ip=1 succeeded with OK after 0.3125066 seconds and 0 retries
[13:05:30 INF] Execution of http request to https://speckle.xyz//graphql succeeded with OK after 0.2798989 seconds and 0 retries
[13:05:30 INF] Execution of graphql request to get Dictionary`2 succeeded after 0.316219 seconds
Fetching headless doc 'Untitled'
    with template: 'No template'
    Model units:Millimeters
[13:05:50 INF] Max concurrent requests = 1
[13:06:50 INF] Max concurrent requests = 1
[13:07:08 ERR] HTTP POST /grasshopper responded 500 in 100037.2854 ms
System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
 ---> System.TimeoutException: The operation was canceled.
 ---> System.Threading.Tasks.TaskCanceledException: The operation was canceled.
 ---> System.IO.IOException: Unable to read data from the transport connection: La operación de E/S se anuló por una salida de subproceso o por una solicitud de aplicación..
 ---> System.Net.Sockets.SocketException (995): La operación de E/S se anuló por una salida de subproceso o por una solicitud de aplicación.
   --- End of inner exception stack trace ---
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError , CancellationToken )
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 )
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage , Boolean , Boolean , CancellationToken )
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.HttpClient.SendAsyncCore(HttpRequestMessage , HttpCompletionOption , Boolean , Boolean , CancellationToken )
   --- End of inner exception stack trace ---
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpClient.SendAsyncCore(HttpRequestMessage , HttpCompletionOption , Boolean , Boolean , CancellationToken )
   at rhino.compute.ReverseProxyModule.SendProxyRequest(HttpRequest initialRequest, HttpMethod method, String baseurl) in D:\BuildAgent\work\4852f584398a78e4\src\rhino.compute\ReverseProxy.cs:line 140
   at rhino.compute.ReverseProxyModule.ReverseProxyGrasshopper(HttpRequest req, HttpResponse res) in D:\BuildAgent\work\4852f584398a78e4\src\rhino.compute\ReverseProxy.cs:line 196
   at Carter.CarterExtensions.<>c__DisplayClass1_0.<<CreateRouteHandler>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at rhino.compute.ApiKeyMiddleware.InvokeAsync(HttpContext context) in D:\BuildAgent\work\4852f584398a78e4\src\rhino.compute\ApiKeyMiddleware.cs:line 34
   at Serilog.AspNetCore.RequestLoggingMiddleware.Invoke(HttpContext httpContext)
[13:07:09 ERR] Connection id "0HMTCDMCKEBA5", Request id "0HMTCDMCKEBA5:00000002": An unhandled exception was thrown by the application.
System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
 ---> System.TimeoutException: The operation was canceled.
 ---> System.Threading.Tasks.TaskCanceledException: The operation was canceled.
 ---> System.IO.IOException: Unable to read data from the transport connection: La operación de E/S se anuló por una salida de subproceso o por una solicitud de aplicación..
 ---> System.Net.Sockets.SocketException (995): La operación de E/S se anuló por una salida de subproceso o por una solicitud de aplicación.
   --- End of inner exception stack trace ---
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError , CancellationToken )
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.GetResult(Int16 )
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage , Boolean , Boolean , CancellationToken )
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.HttpClient.SendAsyncCore(HttpRequestMessage , HttpCompletionOption , Boolean , Boolean , CancellationToken )
   --- End of inner exception stack trace ---
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpClient.SendAsyncCore(HttpRequestMessage , HttpCompletionOption , Boolean , Boolean , CancellationToken )
   at rhino.compute.ReverseProxyModule.SendProxyRequest(HttpRequest initialRequest, HttpMethod method, String baseurl) in D:\BuildAgent\work\4852f584398a78e4\src\rhino.compute\ReverseProxy.cs:line 140
   at rhino.compute.ReverseProxyModule.ReverseProxyGrasshopper(HttpRequest req, HttpResponse res) in D:\BuildAgent\work\4852f584398a78e4\src\rhino.compute\ReverseProxy.cs:line 196
   at Carter.CarterExtensions.<>c__DisplayClass1_0.<<CreateRouteHandler>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at rhino.compute.ApiKeyMiddleware.InvokeAsync(HttpContext context) in D:\BuildAgent\work\4852f584398a78e4\src\rhino.compute\ApiKeyMiddleware.cs:line 34
   at Serilog.AspNetCore.RequestLoggingMiddleware.Invoke(HttpContext httpContext)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)

teocomi · 4 September 2023 14:37

Hey @jan-casas ,

Judging from the error message, the problem is with the RhinoCompute server.
I’m not sure why that’s showing up in our logs, but the /grasshopper is not ours and reading a bit more in the exception, I see it comes from rhino.compute\ReverseProxy.cs:line 140.

If you have any logs from the Rhino.Compute server you might be able to see what’s causing the 500 error there…

jan-casas · 4 September 2023 18:08

I apologize for the misunderstanding.
I assumed that the problem was related to speckle because the script was not working properly when connecting the receive component. I will investigate further and let you know if I find anything.
Thank you!