search

eclipse-archived / codewind

The official repository of the Eclipse Codewind project
https://codewind.dev
Eclipse Public License 2.0
113 stars 45 forks source link

SVT: Fatal error in Appsody Eclipse MicroProfile project due to an error with the pom.xml file #1202

Open sujeilyfonseca opened 4 years ago

sujeilyfonseca commented 4 years ago

Codewind version: codewind-0.6.0-201911151544.vsix OS: VM with Windows 10

IDE extension version: 0.6.0 IDE version: Code 1.40.1

Description: Fatal error in Appsody Eclipse MicroProfile project due to an error with the pom.xml file

[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] failed to load external entity "pom.xml"
[Container] failed to load external entity "pom.xml"
[Container] failed to load external entity "pom.xml"
[Container] Project pom.xml is missing the required parent:
[Container] 
[Container]   <parent>
[Container]     <groupId>dev.appsody</groupId>
[Container]     <artifactId>java-microprofile</artifactId>
[Container]     <version></version>
[Container]     <relativePath/>
[Container]   </parent>
[Container]   
[Container] [Error] FATAL error APPSODY_PREP command received an error.  The controller is exiting: exit status 1
[Error] Error in 'appsody run': exit status 1

Logs: cw-appsody-eclipse-microprofile.appsody.log filewatcherd-1.log codewind.log

@jagraj

sujeilyfonseca commented 4 years ago

/area appsody /priority stopship

sghung commented 4 years ago

This issue is 100% reproducible, I am trying to isolate the issue. Examining the appsody microprofile stack from 0.2.18 to 0.2.19, the changes there would not have caused the error.

When I try git checkout 60b1992bce2295a16b7c56f8e1948ab287c87c6f for a master commit, that works fine. When I tried using various 0.6.0 commits, I get the error. So I suspect this is something wrong in 0.6.0.

sghung commented 4 years ago

More investigation notes: the error comes from thevalidate.sh script from the appsody stack. 

# Check child pom for required parent project
if [ "${p_groupId}" != "${a_groupId}" ] || [ "${p_artifactId}" != "${a_artifactId}" ]; then
  echo "Project pom.xml is missing the required parent:

  <parent>
    <groupId>${a_groupId}</groupId>
    <artifactId>${a_artifactId}</artifactId>
    <version>${a_range}</version>
    <relativePath/>
  </parent>
  "
  exit 1
fi

I believe the three entries for failed to load external entity "pom.xml" is caused by that if statement.

sghung commented 4 years ago

@sujeilyfonseca can you try something for me? I found that if I use the codewind-data directory (or codewind-workspace), I would see this. Can you try putting it in another directory like C:\temp, such that the path is like C/temp/cw-appsody-eclipse-microprofile-1

In case it wasn't in that directory, let me know. I couldn't quite tell from the logs whether it was confirmed to be there, or whether it is just being copied there.

sujeilyfonseca commented 4 years ago

Thank you for working to solve this problem, @sghung!

Originally, both projects that were failing due to pom.xml were located in c:\codewind-workspace,

I created a project in a different location, but I still see the problem:

Screen Shot 2019-11-20 at 1 06 02 AM
jagraj commented 4 years ago

I tried to reproduce this problem after migrating from Codewind 0.4 to Codewind 0.6 and I got into following issue. (https://github.com/eclipse/codewind/issues/1228)

makandre commented 4 years ago

What does the pom.xml in your project look like? Specifically for this part:

   <parent><!--required parent POM-->
        <groupId>dev.appsody</groupId>
        <artifactId>java-microprofile</artifactId>
        <version>[0.2, 0.3)</version>
        <relativePath/>
    </parent>

    <groupId>dev.appsody.starter.java-microprofile</groupId>
    <artifactId>starter-app</artifactId>
    <version>1.0-SNAPSHOT</version>
    <packaging>war</packaging>
sghung commented 4 years ago

The only time I can consistently reproduce this, is by using a directory that codewind is mounting.

For example, when I do run.sh (it uses codewind/codewind-workspace), if I run: docker inspect -f '{{ .Mounts }}' 2a53207bd4e1

I get: [{bind /var/run/docker.sock /var/run/docker.sock rw true rprivate} {bind /Users/stevenhung/git/codewind/codewind-workspace /mounted-workspace rw true rprivate} {volume codewind_cw-workspace /var/lib/docker/volumes/codewind_cw-workspace/_data /codewind-workspace local rw true }]

If I use codewind/codewind-workspace, I get the error. If I shell into the PFE container, I do see the pom.xml in /mounted-workspace/. That pom.xml does have:

<parent><!--required parent POM-->
        <groupId>dev.appsody</groupId>
        <artifactId>java-microprofile</artifactId>
        <version>[0.2, 0.3)</version>
        <relativePath/>
    </parent>

    <groupId>dev.appsody.starter.java-microprofile</groupId>
    <artifactId>starter-app</artifactId>
    <version>1.0-SNAPSHOT</version>
    <packaging>war</packaging>

sujeilyfonseca did say she's using another directory now, but I still can't reproduce that scenario

sujeilyfonseca commented 4 years ago

@makandre, the pom.xml has the content you specified:

    <parent><!--required parent POM-->
        <groupId>dev.appsody</groupId>
        <artifactId>java-microprofile</artifactId>
        <version>[0.2, 0.3)</version>
        <relativePath/>
    </parent>

    <groupId>dev.appsody.starter.java-microprofile</groupId>
    <artifactId>starter-app</artifactId>
    <version>1.0-SNAPSHOT</version>
    <packaging>war</packaging>
sghung commented 4 years ago

@sujeilyfonseca what happens if you call docker inspect -f '{{ .Mounts }}' 2a53207bd4e1 (replace the container ID with pfe's container ID via calling docker ps)

Also, can you attach the logs for running on c:\cw-temp\cw-appsody-microprofile-2? In particular, the appsody logs, filewatcher, and pfe logs. Thank you. I just want to verify some of the output there.

makandre commented 4 years ago

Putting your project in the mounted dir (which for an official install on Windows would be C:\codewind-data) is for sure to cause problems and we tell users they must not do that.

So let's set that aside and make sure our env is correct:

  1. where is the project physically located?
  2. does C:\codewind-data exists?
  3. is it shared to docker? Can docker mount it?
  4. do you see a copies of your appsody projects in that directory?
sujeilyfonseca commented 4 years ago

@sghung:

PS C:\Users\Administrator> docker inspect -f '{{ .Mounts }}' 0513e9656650
[{volume codewind_cw-workspace /var/lib/docker/volumes/codewind_cw-workspace/_data /codewind-workspace local rw true } {bind  /host_mnt/c/codewind-data /mounted-workspace  rw true rprivate} {bind  /var/run/docker.sock /var/run/docker.sock  rw true rprivate}]

PFE logs are full of same error messages, so there's not much to see:

[20/11/19 22:04:19 cw-appsody-eclipse-microprofile-1] [INFO] pingApplications: Application state error message: Http request is failed due to timeout error
[20/11/19 22:04:21 cw-appsody-eclipse-microprofile-1] [INFO] pingApplications: Application state error message: Error: connect EHOSTUNREACH 172.21.0.8:9080
PS C:\Users\Administrator>

cw-appsody-microprofile-2.txt codewind.log filewatcherd-1.log codewind-pfe.txt

sujeilyfonseca commented 4 years ago

@makandre:

(1) Originally, both projects that were failing due to pom.xml were located in c:\codewind-workspace, not under c:\codewind-data (cw-appsody-eclipse-microprofile and cw-appsody-eclipse-microprofile-1).

Recent projects are under c:/cw-temp/, which is a directory I have created (cw-appsody-microprofile-1 and cw-appsody-microprofile-2):

Screen Shot 2019-11-20 at 5 17 06 PM

The one with [Running] status is stopped, and there is another issue to address that wrong application status.

(2) Yes, c:\codewind-data exists.

(3) Yes, and I can create other projects without any problem.

(4) Yes:

Screen Shot 2019-11-20 at 5 19 20 PM

malincoln commented 4 years ago

I tried to reproduce this problem after migrating from Codewind 0.4 to Codewind 0.6 and I got into following issue. (#1228)

Note: 1228 is now closed due to network issue.

makandre commented 4 years ago

@sujeilyfonseca it looks fine but maybe I can suggest trying this:

  1. Stop codewind
  2. Delete the codewind docker volume plus any that ends with -dep
  3. Grep for and delete appsody docker images
  4. Restart codewind
jagraj commented 4 years ago

@makandre Is this workaround for the user when they get into this problem.? We don't loose meta data of codewind when we delete codewind workspace volume.?

makandre commented 4 years ago

@jagraj as discussed on the call, we are going to put in something to block users from creating projects in codewind-data, so that takes care of how we initially got into this situation.

So that leave us with why @sujeilyfonseca is still seeing this issue, and I highly suspect maybe the env is now in a bad state due to hitting the initial problem (since you you mentioned you were able to create appsody java-mp projects on your system). Hence I'm suggesting the above steps to try to set her env back to a good state

Alternatively, ping me the creds to the VM and I can hop on the system to take a look as well

sujeilyfonseca commented 4 years ago

I followed @makandre's suggestions, but I still see the problem. I contacted him, and he will take a look at the VM to debug the problem. The environment could be in a bad state due to hitting the initial problem, but he would see if there is a way for the user to recover from this problem.

It is important to note that this problem occurred without including any projects within c:\codewind-data. It was originally achieved after migrating a project from Codewind 0.5.0 and after creating another project in c:\codewind-workspace with codewind-0.6.0-201911151544.vsix. After that, I created projects in a new c:\cw-temp directory, but I still got the same errors with Appsody Eclipse MicroProfile. I can create any other projects without any problem.

makandre commented 4 years ago

I went onto the vm. I noticed there were some stale files under codewind-data directory, which I suspect were left behind from the initial problem. I cleaned those up.

I was able to create an appsody microprofile project, and it started up fine.

@sujeilyfonseca by any chance were you creating projects using same names before and after you move the projects out of the codewind-data directory?

I think what happened was, the "bad" project was still in the mounted codewind-data directory when you recreated the project in the new location. And then the new project files when synced to PFE, was merged together with the "bad" project files that were left behind, hence you continued to see the problem.

Anyways, now that we are going to block users from creating projects in the codewind-data directory, users would never run into this situation.

sujeilyfonseca commented 4 years ago

Thanks for taking a look at the VM, @makandre!

No, I used numbers or dates to differentiate which projects were created first.

makandre commented 4 years ago

Then I'm really not sure what led us here. But now it is back to normal it seems, pls confirm if you can create and run microprofile project on it

jagraj commented 4 years ago

I tried to create project inside c:\codewind-data folder in eclipse plugin and we already blocking user to create the projects here. We are checking in VSCode if we have similar check.

Screen Shot 2019-11-21 at 2 41 37 PM

sujeilyfonseca commented 4 years ago

I confirm that I was able to create an Appsody Eclipse MicroProfile project after @makandre cleaned out stale files:

Screen Shot 2019-11-21 at 1 44 56 PM

However, I was able to reproduce the problem again on my machine. Therefore, @jagraj and I would try to see what could cause the problem and try to reproduce the problem on another machine.

naveenkaratekid commented 4 years ago

I too was able to reproduce this issue on my machine: After migration, the Appsody MP template fails to build.

Here are the logs: pfe.txt

Screen Shot 2019-11-21 at 5 07 43 PM

Appsody MP log fail after migration.txt

filewatcherd-1.log

codewind.log

jagraj commented 4 years ago

I tried to reproduce this problem on one of my windows VM where migration worked fine with eclipse plugin but failed with VS Code migration on same machine.

@rajivnathan I see file-watcher error in the failure. Can your team can take a look at these logs.?

[Container] Running APPSODY_PREP command: ../validate.sh && mvn -B -Dmaven.repo.local=/mvn/repository install -DskipTests && /project/install-dev-deps.sh
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] Installing parent dev.appsody:java-microprofile:0.2.19
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [INFO] Scanning for projects...
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [INFO] 
[Container] [INFO] -------------------< dev.appsody:java-microprofile >--------------------
[Container] [INFO] Building java-microprofile 0.2.19
[Container] [INFO] --------------------------------[ pom ]---------------------------------
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [INFO] 
[Container] [INFO] --- maven-enforcer-plugin:3.0.0-M2:enforce (enforce-versions) @ java-microprofile ---
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [INFO] Skipping Rule Enforcement.
[Container] [INFO] 
[Container] [INFO] --- maven-install-plugin:2.4:install (default-install) @ java-microprofile ---
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] [INFO] Installing /project/user-app/../pom.xml to /mvn/repository/dev/appsody/java-microprofile/0.2.19/java-microprofile-0.2.19.pom
[Container] [INFO] ------------------------------------------------------------------------
[Container] [INFO] BUILD SUCCESS
[Container] [INFO] ------------------------------------------------------------------------
[Container] [INFO] Total time:  10.390 s
[Container] [INFO] Finished at: 2019-11-21T21:50:47Z
[Container] [INFO] ------------------------------------------------------------------------
[Container] failed to load external entity "pom.xml"
[Container] failed to load external entity "pom.xml"
[Container] [Warning] An error occured in the file watcher lstat /project/user-app/pom.xml: stale NFS file handle
[Container] failed to load external entity "pom.xml"
[Container] Project pom.xml is missing the required parent:
[Container] 
[Container]   <parent>
[Container]     <groupId>dev.appsody</groupId>
[Container]     <artifactId>java-microprofile</artifactId>
[Container]     <version></version>
[Container]     <relativePath/>
[Container]   </parent>
[Container]   
[Container] [Error] FATAL error APPSODY_PREP command received an error.  The controller is exiting: exit status 1
[Error] Error in 'appsody run': exit status 1

Screen shot image

Logs.. appsody.log pfe.txt codewind.log filewatcherd-1.log

sujeilyfonseca commented 4 years ago

Jag and I could not reproduce the problem in Eclipse. We both used the same environment that had problems with the Appsody Eclipse MicroProfile project after migration. Therefore, this problem could be related to the VS code IDE:

Screen Shot 2019-11-21 at 6 00 04 PM
jgwest commented 4 years ago

@jagraj re: the file watcher message, that is coming from Appsody. Appsody has it's own file watcher which is unrelated to ours (and unrelated to Turbine).

makandre commented 4 years ago

@jagraj re https://github.com/eclipse/codewind/issues/1202#issuecomment-557298418, the appsody.log attached shows server started successfully. It also shows project files mounted from C:\codewind-workspace, which would not happen in 0.6.0. I think this is the wrong log

makandre commented 4 years ago 
Running docker command: docker run --rm -P --name cw-apjava01-7a182690-0cd2-11ea-b7b5-237a46a23e4f --network codewind_network -v /C/codewind-data/apjava01/src:/project/user-app/src -v /C/codewind-data/apjava01/pom.xml:/project/user-app/pom.xml -v /C/codewind-data/.extensions/codewind-appsody-extension/bin/appsody-controller:/appsody/appsody-controller -t --entrypoint /appsody/appsody-controller appsody/java-microprofile:0.2 --mode=run
[Container] Running APPSODY_PREP command: ../validate.sh && mvn -B -Dmaven.repo.local=/mvn/repository install -DskipTests && /project/install-dev-deps.sh
[Container] [Warning] Failed to add directory to recursive file watching list: /project/user-applstat /project/user-app/pom.xml: stale NFS file handle
[Container] Error: Could not find Maven pom.xml
[Container] 
[Container]   * The project directory (containing an .appsody-conf.yaml file) must contain a pom.xml file.
[Container]   * On Windows and MacOS, the project directory should also be shared with Docker: 
[Container]     - Win: https://docs.docker.com/docker-for-windows/#shared-drives
[Container]     - Mac: https://docs.docker.com/docker-for-mac/#file-sharing
[Container]   
[Container] [Error] FATAL error APPSODY_PREP command received an error.  The controller is exiting: exit status 1
[Error] Error in 'appsody run': exit status 1

I witnessed this first-hand doing a migration on @sujeilyfonseca VM.

Seeing this is on Windows, could it be that the project dir in codewind-data is getting overwritten or replaced somehow after migration finished and appsody mounts it? Could that be why the mounted files became stale? That's just purely a guess; I really don't know.

It's lights out over here, @tobespc could you have a look from a migration angle and see if there's anything obvious going on perhaps?

jagraj commented 4 years ago

Myself, Sujeily and Naveen all of us reproduced this problem. We are wondering why this problem happens only with VSCode and not from Eclipse plugin.?

makandre commented 4 years ago

Could be due to a timing or sequence of things happening

jagraj commented 4 years ago

On same failure environment I tried to create new project which was failed after migration and that built fine without any problems.

makandre commented 4 years ago

I think got this figured out!

The stale NFS file handle error everyone is running into, it is because of https://github.com/appsody/appsody/issues/512. Basically, anytime a single mounted file (i.e. the pom.xml in this case) is modified on Windows, it becomes stale and unreadable. (A big THANK YOU to @jgwest for finding this issue.)

As to what is modifying that file during the migration, it is most likely the Java Extension tools in VSCode that's doing it. I went and tried the migration again with the Java Extensions tools disabled and the project runs fine after migration (but of course if I then make any edit to the pom.xml, then I hit the stale NFS file handle problem again.)

malincoln commented 4 years ago

Will move to Hot while we wait on fix for 512 from Appsody team

malincoln commented 4 years ago

/priority hot /remove-priority stopship

malincoln commented 4 years ago

/priority hot /remove-priority stopship

jgwest commented 4 years ago

(Not sure why the bot didn't catch the last two comments 🤔, sorry about that @malincoln)

malincoln commented 4 years ago

no worries

sghung commented 4 years ago

From the appsody stacks side, the open liberty appsody stack (which will replace the microprofile stack) PR is here: https://github.com/appsody/stacks/pull/573/files

I see documentation has been updated to discourage single file mounts (https://github.com/appsody/website/issues/455), but I don't see the validation changes added to the appsody stack validate. I will need to followup with that in addition to the spring stack.

malincoln commented 4 years ago

targeting 0.9.0

sghung commented 4 years ago

Followup with Neeraj: make sure we have a specific date on when this is deprecated.

sghung commented 4 years ago

The microprofile template now mentions "deprecated" , so I don't think it should be marked as hot anymore

sghung commented 4 years ago

I talked with Sujeily and got agreement to lower the severity because the template is tagged with "deprecated" now