Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Project build when referencing RProvider hangs forever (ubuntu-latest - github actions) #238

Closed
AndrewIOM opened this issue Oct 26, 2021 · 2 comments
Closed

Project build when referencing RProvider hangs forever (ubuntu-latest - github actions) #238

AndrewIOM opened this issue Oct 26, 2021 · 2 comments
Labels
Priority: Medium Status: Available Type: Bug Something is broken!

Comments

@AndrewIOM
Copy link
Collaborator

Describe the bug
Projects that reference RProvider fail to build when using Ubuntu 20.04 as the OS within Github Actions using FAKE. When dotnet build is called for the specific project, it hangs forever.

To Reproduce
Steps to reproduce the behavior:

  1. Enable ubuntu-latest in the github actions script for RProvider itself or Deedle (see Configure R plugin for RProvider v2 Deedle#538)
  2. The build will hang forever on Ubuntu agent but complete on a macos or windows agent. For Deedle, this is the RProvider plugin project; for RProvider, this is the test project.

Expected behavior
No hangs and successful build.

Environment (please complete the following information):

  • OS: Github Actions - ubuntu latest (20.04)
  • OS Version: 20.04
  • Using in script or library: library
  • RProvider 2.0.1-beta2
  • Installed R Version 4.0.2
@AndrewIOM
Copy link
Collaborator Author

Bit puzzled with this one. Works fine in Ubuntu 20.04 docker image with various versions of R. Could to be something specific to GitHub Actions. This is the Dockerfile:

# https://hub.docker.com/_/microsoft-dotnet
FROM mcr.microsoft.com/dotnet/sdk:6.0-focal AS build

ENV DEBIAN_FRONTEND noninteractive

RUN apt-get update && apt-get -y install --no-install-recommends --no-install-suggests \
        ca-certificates software-properties-common gnupg2 gnupg1 \
      && apt-key adv --keyserver keyserver.ubuntu.com --recv-keys E298A3A825C0D65DFD57CBB651716619E084DAB9 \
      && add-apt-repository 'deb https://cloud.r-project.org/bin/linux/ubuntu bionic-cran35/' \
      && apt-get install r-base -y

WORKDIR /app
COPY ./src /app/src
COPY ./docs /app/docs
COPY ./tests /app/tests
COPY ./build.fsx /app/build.fsx
COPY ./paket.dependencies /app/paket.dependencies
COPY ./paket.lock /app/paket.lock
COPY ./RELEASE_NOTES.md /app/RELEASE_NOTES.md
COPY ./RProvider.sln /app/RProvider.sln
COPY ./RProvider.Tests.sln /app/RProvider.Tests.sln
COPY ./.config /app/.config
COPY ./.paket /app/.paket

RUN dotnet tool restore
ENV RPROVIDER_LOG=/app/log.log
VOLUME [ "/app/log.log" ]
ENTRYPOINT ["dotnet", "fake", "run"]

and the log:

[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] Starting build types.
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] initAndGenerate: starting
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] [Get server]
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] [Check last server]
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] [Make new server]
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] Starting new connection to server from client
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] Setting execute permission on '/app/src/RProvider/bin/Release/net5.0/server/linux-x64/RProvider.Server'
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] Starting server '/app/src/RProvider/bin/Release/net5.0/server/linux-x64/RProvider.Server' with arguments 'RInteropServer_856_6293699_781413576 "/tmp/tmpnA3EQX.tmp"' (exists=true)
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] R_HOME not set
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] findRLocation
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] getRLocation
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] getRProviderConfValue 'R_HOME'
[10/26/2021 18:11:09] [Pid:856, Tid:1, Apid:1] getRProviderConfValue - Home: '/root'
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Checking '~/.rprovider.conf' for R_HOME value: None
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Calling 'R --print-home'
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] R --print-home returned: /usr/lib/R

[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Setting R_HOME to: /usr/lib/R
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] findRLocation: file='/usr/lib/R/lib/libR.so'
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Setting R_HOME as /usr/lib/R
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] R_HOME set as /usr/lib/R
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] Starting 'RProvider.Server' with arguments '[|"RInteropServer_856_6293699_781413576"; "/tmp/tmpnA3EQX.tmp"|]'
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] Ready for connections..
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Attempting to connect via inter-process communication
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] Waiting for parent process pid=856 (System.Diagnostics.Process (dotnet))
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] Server started, running event loop
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] server event loop: starting
 NotOpened
[10/26/2021 18:11:10] [Pid:856, Tid:4, Apid:1] Attempting to connect pipe client...
[10/26/2021 18:11:10] [Pid:856, Tid:4, Apid:1] [Client Pipe log]: Connecting to named pipe
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] getRLocation
[10/26/2021 18:11:10] [Pid:856, Tid:8, Apid:1] [Client Pipe log]: Connected.
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] findRLocation: file='/usr/lib/R/lib/libR.so'
[10/26/2021 18:11:10] [Pid:883, Tid:7, Apid:1] [Server Pipe log]: Connected to client.
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Got some server
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] Sending command: get init error message...
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 1
  MethodName: InitializationErrorMessage
[10/26/2021 18:11:10] [Pid:883, Tid:5, Apid:1] [Server Pipe log]: Received Request
  CallId: 1
  MethodName: InitializationErrorMessage
[10/26/2021 18:11:10] [Pid:883, Tid:5, Apid:1] [Server Pipe log]: Sending Response
  CallId: 1
  Succeeded: True
  Response: <null>
[10/26/2021 18:11:10] [Pid:856, Tid:4, Apid:1] [Client Pipe log]: Received Response
  CallId: 1
  Succeeded: True
  Response: <null>
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] [Get server]
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] [Check last server]
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] [Found lastServer]
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] generateTypes: getting packages
[10/26/2021 18:11:10] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 2
  MethodName: GetPackages
[10/26/2021 18:11:10] [Pid:883, Tid:7, Apid:1] [Server Pipe log]: Received Request
  CallId: 2
  MethodName: GetPackages
[10/26/2021 18:11:10] [Pid:883, Tid:7, Apid:1] Adding work item to queue
[10/26/2021 18:11:10] [Pid:883, Tid:7, Apid:1] Debug 1
[10/26/2021 18:11:10] [Pid:883, Tid:7, Apid:1] Debug 2
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] server event loop: got work item
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] In queue
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] Communicating with R to get packages
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] eval(.packages(all.available=T))
[10/26/2021 18:11:10] [Pid:883, Tid:1, Apid:1] engine: Creating and initializing instance (sizeof<IntPtr>=8)
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] engine: Created & initialized instance
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] [DEBUG] MEF Container 1: RProvider.dll is at /app/src/RProvider/bin/Release/net5.0/server/linux-x64/
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] RProvider configuration file is /app/src/RProvider/bin/Release/net5.0/RProvider.Runtime.dll.config
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] Attempting to load config file '/app/src/RProvider/bin/Release/net5.0/RProvider.Runtime.dll.config'
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] [DEBUG] MEF Container 2: Probing locations = []
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] [DEBUG] MEF Container 3: Catalog count = 2
[10/26/2021 18:11:11] [Pid:883, Tid:1, Apid:1] Result: System.String[]
[10/26/2021 18:11:11] [Pid:883, Tid:7, Apid:1] [Server Pipe log]: Sending Response
  CallId: 2
  Succeeded: True
  Response: System.String[]
[10/26/2021 18:11:11] [Pid:856, Tid:7, Apid:1] [Client Pipe log]: Received Response
  CallId: 2
  Succeeded: True
  Response: System.String[]
[10/26/2021 18:11:11] [Pid:856, Tid:1, Apid:1] initAndGenerate: finished
[10/26/2021 18:11:11] [Pid:856, Tid:1, Apid:1] RProvider constructor succeeded
[10/26/2021 18:11:11] [Pid:856, Tid:1, Apid:1] Defined static Parameters System.String FileName
[10/26/2021 18:11:11] [Pid:856, Tid:1, Apid:1] RData added namespace RProvider.RData
[10/26/2021 18:11:13] [Pid:856, Tid:1, Apid:1] [Get server]
[10/26/2021 18:11:13] [Pid:856, Tid:1, Apid:1] [Check last server]
[10/26/2021 18:11:13] [Pid:856, Tid:1, Apid:1] [Found lastServer]
[10/26/2021 18:11:13] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 3
  MethodName: LoadPackage
  Parameters:
    base
[10/26/2021 18:11:13] [Pid:883, Tid:9, Apid:1] [Server Pipe log]: Received Request
  CallId: 3
  MethodName: LoadPackage
  Parameters:
    base
[10/26/2021 18:11:13] [Pid:883, Tid:9, Apid:1] Adding work item to queue
[10/26/2021 18:11:13] [Pid:883, Tid:9, Apid:1] Debug 1
[10/26/2021 18:11:13] [Pid:883, Tid:9, Apid:1] Debug 2
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] server event loop: got work item
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] In queue
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] eval(require(base))
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:13] [Pid:883, Tid:9, Apid:1] [Server Pipe log]: Sending Response
  CallId: 3
  Succeeded: True
  Response: <null>
[10/26/2021 18:11:13] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 4
  MethodName: GetBindings
  Parameters:
    base
[10/26/2021 18:11:13] [Pid:883, Tid:5, Apid:1] [Server Pipe log]: Received Request
  CallId: 4
  MethodName: GetBindings
  Parameters:
    base
[10/26/2021 18:11:13] [Pid:883, Tid:5, Apid:1] Adding work item to queue
[10/26/2021 18:11:13] [Pid:883, Tid:5, Apid:1] Debug 1
[10/26/2021 18:11:13] [Pid:883, Tid:5, Apid:1] Debug 2
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] server event loop: got work item
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] In queue
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] evalto(function (pkgName) {
    require(pkgName, character.only=TRUE)
    pkgListing <- ls(paste("package:",pkgName,sep=""))
    lapply(
        pkgListing,
        function (pname) {
            pval <- get(pname)
            ptype <- typeof(pval)
            if (ptype == "closure") {
                list(name=pname, type=ptype, params=list(names(formals(pname))))
            } else {
                list(name=pname, type=ptype, params=NA)
            }
        }
    )
}, fsr_883_1)
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] eval(fsr_883_1('base'))
[10/26/2021 18:11:13] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:13] [Pid:883, Tid:5, Apid:1] [Server Pipe log]: Sending Response
  CallId: 4
  Succeeded: True
  Response: System.Tuple`2[System.String,System.String][]
[10/26/2021 18:11:13] [Pid:856, Tid:6, Apid:1] [Client Pipe log]: Received Response
  CallId: 4
  Succeeded: True
  Response: System.Tuple`2[System.String,System.String][]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Generating type for RData,FileName="data/sample.rdata"
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Get server]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Check last server]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Found lastServer]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 5
  MethodName: GetRDataSymbols
  Parameters:
    /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] [Server Pipe log]: Received Request
  CallId: 5
  MethodName: GetRDataSymbols
  Parameters:
    /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] Adding work item to queue
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] Debug 1
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] Debug 2
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] server event loop: got work item
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] In queue
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`new.env`())
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`load`(file=fsr_883_2, envir=fsr_883_3))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`ls`(envir=fsr_883_4))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={pi}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_5, envir=fsr_883_6))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcano}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_7, envir=fsr_883_8))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[,]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcanoList}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_9, envir=fsr_883_10))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcanoMean}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_11, envir=fsr_883_12))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] [Server Pipe log]: Sending Response
  CallId: 5
  Succeeded: True
  Response: System.Tuple`2[System.String,System.Type][]
[10/26/2021 18:11:14] [Pid:856, Tid:6, Apid:1] [Client Pipe log]: Received Response
  CallId: 5
  Succeeded: True
  Response: System.Tuple`2[System.String,System.Type][]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member pi
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member volcano
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member volcanoList
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member volcanoMean
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Finished generating types for /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Generating type for RData,FileName="data/sample.rdata"
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Get server]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Check last server]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Found lastServer]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 6
  MethodName: GetRDataSymbols
  Parameters:
    /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] [Server Pipe log]: Received Request
  CallId: 6
  MethodName: GetRDataSymbols
  Parameters:
    /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] Adding work item to queue
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] Debug 1
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] Debug 2
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] server event loop: got work item
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] In queue
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`new.env`())
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`load`(file=fsr_883_13, envir=fsr_883_14))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`ls`(envir=fsr_883_15))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={pi}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_16, envir=fsr_883_17))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcano}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_18, envir=fsr_883_19))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[,]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcanoList}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_20, envir=fsr_883_21))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcanoMean}
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_22, envir=fsr_883_23))
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:14] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:14] [Pid:883, Tid:8, Apid:1] [Server Pipe log]: Sending Response
  CallId: 6
  Succeeded: True
  Response: System.Tuple`2[System.String,System.Type][]
[10/26/2021 18:11:14] [Pid:856, Tid:4, Apid:1] [Client Pipe log]: Received Response
  CallId: 6
  Succeeded: True
  Response: System.Tuple`2[System.String,System.Type][]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member pi
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member volcano
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member volcanoList
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Adding member volcanoMean
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Finished generating types for /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] Generating type for RData,FileName="data/sample.rdata"
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Get server]
[10/26/2021 18:11:14] [Pid:856, Tid:1, Apid:1] [Check last server]
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] [Found lastServer]
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 7
  MethodName: GetRDataSymbols
  Parameters:
    /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:15] [Pid:883, Tid:9, Apid:1] [Server Pipe log]: Received Request
  CallId: 7
  MethodName: GetRDataSymbols
  Parameters:
    /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:15] [Pid:883, Tid:9, Apid:1] Adding work item to queue
[10/26/2021 18:11:15] [Pid:883, Tid:9, Apid:1] Debug 1
[10/26/2021 18:11:15] [Pid:883, Tid:9, Apid:1] Debug 2
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] server event loop: got work item
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] In queue
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`new.env`())
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`load`(file=fsr_883_24, envir=fsr_883_25))
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`ls`(envir=fsr_883_26))
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={pi}
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_27, envir=fsr_883_28))
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcano}
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_29, envir=fsr_883_30))
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[,]
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcanoList}
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_31, envir=fsr_883_32))
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: key={volcanoMean}
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] eval(base::`get`(x=fsr_883_33, envir=fsr_883_34))
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Output: 
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] GetRDataSymbols: value=System.Double[]
[10/26/2021 18:11:15] [Pid:883, Tid:1, Apid:1] Converting value from R...
[10/26/2021 18:11:15] [Pid:883, Tid:9, Apid:1] [Server Pipe log]: Sending Response
  CallId: 7
  Succeeded: True
  Response: System.Tuple`2[System.String,System.Type][]
[10/26/2021 18:11:15] [Pid:856, Tid:8, Apid:1] [Client Pipe log]: Received Response
  CallId: 7
  Succeeded: True
  Response: System.Tuple`2[System.String,System.Type][]
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] Adding member pi
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] Adding member volcano
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] Adding member volcanoList
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] Adding member volcanoMean
[10/26/2021 18:11:15] [Pid:856, Tid:1, Apid:1] Finished generating types for /app/tests/Test.RProvider/data/sample.rdata
[10/26/2021 18:11:16] [Pid:883, Tid:8, Apid:1] [Server Pipe log]: Pipe has closed.
[10/26/2021 18:11:17] [Pid:883, Tid:8, Apid:1] Posting Stop command
[10/26/2021 18:11:17] [Pid:883, Tid:1, Apid:1] server event loop: got stop command
[10/26/2021 18:11:17] [Pid:883, Tid:1, Apid:1] Event loop finished, shutting down

@AndrewIOM
Copy link
Collaborator Author

Further digging reveals that running on Github Actions ubuntu, the type provider initialisation gets stuck at the following stage:

[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Starting build types.
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] initAndGenerate: starting
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Get server]
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Check last server]
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Make new server]
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Starting new connection to server from client
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Setting execute permission on '/home/runner/.nuget/packages/rprovider/2.0.1-beta3/lib/net5.0/server/linux-x64/RProvider.Server'
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Starting server '/home/runner/.nuget/packages/rprovider/2.0.1-beta3/lib/net5.0/server/linux-x64/RProvider.Server' with arguments 'RInteropServer_8120_130411_1948330603 "/tmp/tmpPOBWE4.tmp"' (exists=true)
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] R_HOME set as /opt/R/4.0.2/lib/R
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] Starting 'RProvider.Server' with arguments '[|"RInteropServer_8120_130411_1948330603"; "/tmp/tmpPOBWE4.tmp"|]'
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] Ready for connections..
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] Waiting for parent process pid=8120 (System.Diagnostics.Process (dotnet))
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Attempting to connect via inter-process communication
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] Server started, running event loop
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] server event loop: starting
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] findRLocation
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] getRLocation
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] findRLocation: file='/opt/R/4.0.2/lib/R/lib/libR.so'
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Made pipe client with state: NotOpened
[10/29/2021 10:16:51] [Pid:8120, Tid:10, Apid:1] Attempting to connect pipe client...
[10/29/2021 10:16:51] [Pid:8120, Tid:10, Apid:1] [Client Pipe log]: Connecting to named pipe
[10/29/2021 10:16:51] [Pid:8120, Tid:5, Apid:1] [Client Pipe log]: Connected.
[10/29/2021 10:16:51] [Pid:8211, Tid:6, Apid:1] [Server Pipe log]: Connected to client.
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Got some server
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] Sending command: get init error message...
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 1
  MethodName: InitializationErrorMessage
[10/29/2021 10:16:51] [Pid:8211, Tid:6, Apid:1] [Server Pipe log]: Received Request
  CallId: 1
  MethodName: InitializationErrorMessage
[10/29/2021 10:16:51] [Pid:8211, Tid:6, Apid:1] [Server Pipe log]: Sending Response
  CallId: 1
  Succeeded: True
  Response: <null>
[10/29/2021 10:16:51] [Pid:8120, Tid:5, Apid:1] [Client Pipe log]: Received Response
  CallId: 1
  Succeeded: True
  Response: <null>
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Get server]
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Check last server]
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Found lastServer]
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] generateTypes: getting packages
[10/29/2021 10:16:51] [Pid:8120, Tid:1, Apid:1] [Client Pipe log]: Sending Request
  CallId: 2
  MethodName: GetPackages
[10/29/2021 10:16:51] [Pid:8211, Tid:7, Apid:1] [Server Pipe log]: Received Request
  CallId: 2
  MethodName: GetPackages
[10/29/2021 10:16:51] [Pid:8211, Tid:7, Apid:1] Adding work item to queue
[10/29/2021 10:16:51] [Pid:8211, Tid:7, Apid:1] Debug 1
[10/29/2021 10:16:51] [Pid:8211, Tid:7, Apid:1] Debug 2
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] server event loop: got work item
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] In queue
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] Communicating with R to get packages
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] eval(.packages(all.available=T))
[10/29/2021 10:16:51] [Pid:8211, Tid:1, Apid:1] engine: Creating and initializing instance (sizeof<IntPtr>=8)
[10/29/2021 10:16:52] [Pid:8120, Tid:5, Apid:1] [Client Pipe log]: Pipe has closed.

@AndrewIOM AndrewIOM mentioned this issue Oct 30, 2021
Merged
6 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Priority: Medium Status: Available Type: Bug Something is broken!
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@AndrewIOM