[Bug]: NullPointerException on pipelines with transforms receiving more than one flow in input

sramazzina commented 1 year ago

Apache Hop version?

2.5.0 and any previous version

Java version?

openjdk-11

Operating system

Linux

What happened?

We are experiencing a NullPointerException on pipelines where we have transforms that receives as input more than one flow. Let me summarize below some of the point that could be interesting for our investigation:

The problem always happen when we have two flows as input of a transform.
The problem always happen at the very beginning of the processRow method and is always related to code where the getInputRow() method is involved in a complex inline instruction (like data.fieldnrs[i] = getInputRowMeta().indexOfValue(meta.getFieldName()[i]); or data.outputRowMeta = getInputRowMeta().clone();) and that method returns null
The problem randomly happens 2 or 3 times (lastly it is this way) per day sometimes or nothing at all for a long time then it apperas again

The fact that is a random problem makes it hard to reproduce and for this reason till now we were unable to catch it. We asked the customer some context data and we got the confirmation that the overall load of the server at the time of the issue is normal. The system isn't under severe stress

I post here some screenshots of the pipeline by putting in evidence the transforms that gives the issue

Issue Priority

Priority: 1

Issue Component

Component: Transforms

sramazzina commented 1 year ago

After months of tries looking for a reproduction path we definitely were able to get it. So let me try to write down something interesting to share with the community so that we can try to elaborate on this.

First thing first. We were able to reproduce the problem by putting the system under light load (that means if we evaluate the 5min load average on linux system we are considering load > 2). We also already said that this happens only for pipelines where we have more than one hop that is entering a target transform.

Therefore

because we started thinking the problem was related in how the BaseTransform.handleGetRow(), I rebuilt the hop-engine module by adding a bunch of log messages in points of the method that I considered critical. I thought it was a good idea to decorate every log message with a bunch of context information to understand better what was happening at the time of the exception
we put together a very simple test pipeline

we emulated the stress on the system by installing and running the stress tool on linux (very useful sudo apt install stress to install it on ubuntu https://www.tecmint.com/linux-cpu-load-stress-test-with-stress-ng-tool/)
we built a very simple script in bash to launch the pipeline by using hop-run repeatedly
we collected the log

As I said the issue randomly happens but after waiting for a while it happened. It is not clear yet were the problem is but it happened. I though it was a good idea start talking about that so I wanted to share everything till now. I attached to this comment the sample pipeline and the two logs related to a good and a failed execution. If someone want to help in investigating about that I'm very happy for that. You can also take a look at the changes made to handleGetRow to get the added log messages here https://github.com/sramazzina/hop/commit/f17fbf5fe33beb94b101f6978baf1d7695f65318

Remember that this issue was inherited from Kettle because we incurred into this also at the time we were using it.

I will be back soon with other comments, let me go back to work hard on solving this issue.

testNullPointer.hpl.zip

logfile-20230908-1642-ok.log

logfile-20230908-1642-ko.2.log

logfile-20230908-1642-ko.1.log

mattcasters commented 10 months ago

I ran hundreds of thousands of iterations of the simple test (see above testNullPointer.hpl) without a reproduction.

Running on Ubuntu 22.04.3 LTS:

openjdk version "11.0.20.1" 2023-08-24
OpenJDK Runtime Environment (build 11.0.20.1+1-post-Ubuntu-0ubuntu122.04)
OpenJDK 64-Bit Server VM (build 11.0.20.1+1-post-Ubuntu-0ubuntu122.04, mixed mode, sharing)

Can you let me know which Run Configuration you're using to reproduce, its settings?

mattcasters commented 10 months ago

Tests running at around 1200% CPU (100% on 12 cores).

mattcasters commented 10 months ago

Reproduction path for me: run the following loop in 5 terminals and wait a few hours. One or more of the terminal tabs will be titled "sleep" and they'll show the NPE stack trace:

while true; do

  sh hop-run.sh -e "hop2 local" -f issue-3056/testNullPointer.hpl -r local
  if [ "$?" -ge 1 ]; then
    echo "Exit after exit code $?" 
    sleep 9999999
    break
  fi

done

apache / hop