Zeebe binding - 1.10.0-rc.5 process variables not stored anymore

fabistb commented 1 year ago

Description

Process variables are variables which are returned from the controller that gets called from the binding, parsed as JSON and forwarded to Zeebe.

Expected Behavior

The Zeebe job worker input binding stores process variables in Zeebe as defined.

Actual Behavior

After deploying Dapr 1.10.0.-rc.5 to our cluster, we had the issue that process variables are not stored in Zeebe anymore.

Dapr Version

1.10.0-rc.5

Cc: @akkie

yaron2 commented 1 year ago

@fabistb have you tried prior 1.10.x RCs, or is this a regression with 1.9?

Also, can you please include details for how to validate / reproduce this?

fabistb commented 1 year ago

@yaron2 , we haven't tried a previous 1.10.x RC. However reverting back to 1.9.6 solves it for us.

We are also just wondering what could cause this since the code hasn't changed a lot recently. https://github.com/dapr/components-contrib/blob/master/bindings/zeebe/jobworker/jobworker.go#L174

Regarding the validation / reproduction the best scenario is probably to check with @akkie.

berndverst commented 1 year ago

@yaron2 , we haven't tried a previous 1.10.x RC. However reverting back to 1.9.6 solves it for us.

We are also just wondering what could cause this since the code hasn't changed a lot recently. https://github.com/dapr/components-contrib/blob/master/bindings/zeebe/jobworker/jobworker.go#L174

Regarding the validation / reproduction the best scenario is probably to check with @akkie.

It seems the issue occurred by upgrading Zeebe Client from 8.0.3 to 8.1.6. Zeebe didn't document any breaking changes but clearly something changed across those minor versions. I have now downgraded this to 8.0.11 (released 4 days ago). Hopefully that will work.

As you know it's a best practice to keep dependencies up to date. It is very surprising that upgrading to a new minor version should have caused this issue, but it is the only explanation we can find.

Dapr/Dapr 1.10.0-rc.7 will contain this downgrade to the latest Zeebe 8.0.X (instead of 8.X.X).

akkie commented 1 year ago

I will have a look regarding the client issue. Do the E2E tests actually run in the pipeline?

https://github.com/dapr/components-contrib/tree/master/tests/e2e/bindings/zeebe

berndverst commented 1 year ago

I will have a look regarding the client issue. Do the E2E tests actually run in the pipeline?

https://github.com/dapr/components-contrib/tree/master/tests/e2e/bindings/zeebe

@akkie No these tests are never run. Not by any of us manually and definitely not by CI.

We will need your help to create a certification test for Zeebe instead. That's the place to run these kinds of integration tests.

Take a look at any of the folders within "tests/certification/bindings" for inspiration. You could probably copy one of those and delete a bunch of things, then migrate over the integration tests you wrote.

Once we have such tests (and every single component metadata property has been covered by tests) we can designate the component as stable. Only stable components receive hotfix support.

akkie commented 1 year ago

@berndverst OK, I will have a look

akkie commented 1 year ago

We have tested with the new RC8 version and it also doesn't work. I will run the Zeebe E2E tests and see if the issue also occurs there too. Give me some time and I can give more feedback

akkie commented 1 year ago

@berndverst @yaron2 I have tested the E2E tests with the actual master branch. All tests run as expected. We have debugged our application and we can see that our workers return all the variables back to the binding. Can it be the case that the body gets lost on the way from the controller to the binding. I know that with 2628 the functionality to propagate a response from the caller back into an input binding was implemented directly for the Zeebe binding. Maybe there is a regression in this code?

akkie commented 1 year ago

The problem occurs also with 1.10.0-rc.1. The last working version is the stable 1.9.6

akkie commented 1 year ago

We have provided an example with which you can reproduce the issue: https://github.com/PlanBGmbH/zeebe-dapr-example

Steps to reproduce:

Checkout Zeebe docker compose: git clone https://github.com/camunda/camunda-platform.git (if you run it on a ARM Mac, then the versions for Zeebe, Operate and Tasklist needs to be changed to 8.2.0-alpha4, connectors needs to be removed)
Run Zeebe: docker compose -f camunda-platform/docker-compose-core.yaml up
Clone the example repo: git clone https://github.com/PlanBGmbH/zeebe-dapr-example.git
Run the service: dotnet run --project "./zeebe-dapr-example/Zeebe.Worker/Zeebe.Worker.csproj"
Deploy the process and instantiate the process (see below)
Open operate and look at the process: http://localhost:8081 (demo, demo)

There are files with the extension .http in the example project. These files can be executed with the RESt Client VSCode extension: https://marketplace.visualstudio.com/items?itemName=humao.rest-client

The deploy-process.http and the first request from the create-instance.http file needs to be executed

fabistb commented 1 year ago

Also tested it on my side. The deploy-process.http returned 400 with VSCode but worked with Rider.

Maybe you can rewrite it to a cUrl statement.

These are the screenshots from the error.

berndverst commented 1 year ago

The master branch is running Zeebe 8.1.6. So it doesn't sound like the issue is caused by the Zeebe version at least as that is what we used in rc1 through rc6. The master branch also has the context propagation changes.

Since master branch works for you it cannot be these particular changes.

berndverst commented 1 year ago

We have provided an example with which you can reproduce the issue: https://github.com/PlanBGmbH/zeebe-dapr-example

Steps to reproduce:

Checkout Zeebe docker compose: git clone https://github.com/camunda/camunda-platform.git (if you run it on a ARM Mac, then the versions for Zeebe, Operate and Tasklist needs to be changed to 8.2.0-alpha4, connectors needs to be removed)

Run Zeebe: docker compose -f camunda-platform/docker-compose-core.yaml up

Clone the example repo: git clone https://github.com/PlanBGmbH/zeebe-dapr-example.git

Run the service: dotnet run --project "./zeebe-dapr-example/Zeebe.Worker/Zeebe.Worker.csproj"

Deploy the process and instantiate the process (see below)

Open operate and look at the process: http://localhost:8081 (demo, demo)

There are files with the extension .http in the example project. These files can be executed with the RESt Client VSCode extension: https://marketplace.visualstudio.com/items?itemName=humao.rest-client

The deploy-process.http and the first request from the create-instance.http file needs to be executed

On M1 Mac Elastic Search 7.17.9 must be used.

berndverst commented 1 year ago

@akkie on AMD64 Linux and ARM64 Mac I cannot run your sample. I get lots of errors of the form

info: Man.Dapr.Sidekick.DaprSidecarHost[0]
      2023/02/14 10:47:01 worker 'calculator' failed to open job stream: rpc error: code = Unavailable desc = connection error: desc = "error reading server preface: read tcp [::1]:54020->[::1]:26500: read: connection reset by peer"
info: Man.Dapr.Sidekick.DaprSidecarHost[0]
      2023/02/14 10:47:01 worker 'calculator' failed to open job stream: rpc error: code = Unavailable desc = connection error: desc = "error reading server preface: read tcp [::1]:54020->[::1]:26500: read: connection reset by peer"
info: Man.Dapr.Sidekick.DaprSidecarHost[0]
      2023/02/14 10:47:01 worker 'calculator' failed to open job stream: rpc error: code = Unavailable desc = connection error: desc = "error reading server preface: EOF"
info: Man.Dapr.Sidekick.DaprSidecarHost[0]
      2023/02/14 10:47:01 worker 'calculator' failed to open job stream: rpc error: code = Unavailable desc = connection error: desc = "error reading server preface: EOF"
info: Man.Dapr.Sidekick.DaprSidecarHost[0]
      2023/02/14 10:47:01 worker 'calculator' failed to open job stream: rpc error: code = Unavailable desc = connection error: desc = "error reading server preface: EOF"

The moment I run dotnet run

akkie commented 1 year ago

@berndverst this errors indicates that zeebe is not running

berndverst commented 1 year ago

 |_  / __| __| _ ) __| |_   _/_\ / __| |/ / |  |_ _/ __|_   _|
  / /| _|| _|| _ \ _|    | |/ _ \\__ \ ' <| |__ | |\__ \ | |
 /___|___|___|___/___|   |_/_/ \_\___/_|\_\____|___|___/ |_|

                       8.2.0-alpha4

2023-02-11 07:29:13.873  INFO 1 --- [           main] i.c.t.Application                        : Starting Application using Java 17.0.6 on b48d161bf34d with PID 1 (/app/classes started by root in /)
2023-02-11 07:29:13.907  INFO 1 --- [           main] i.c.t.Application                        : The following 1 profile is active: "auth"
{"type": "server", "timestamp": "2023-02-11T07:29:15,483Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "version[7.17.5], pid[2], build[default/docker/8d61b4f7ddf931f219e3745f295ed2bbc50c8e84/2022-06-23T21:57:28.736740635Z], OS[Linux/6.1.9-200.fc37.aarch64/aarch64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/18.0.1.1/18.0.1.1+2-6]" }
{"type": "server", "timestamp": "2023-02-11T07:29:15,523Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "JVM home [/usr/share/elasticsearch/jdk], using bundled JDK [true]" }
{"type": "server", "timestamp": "2023-02-11T07:29:15,525Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "JVM arguments [-Xshare:auto, -Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -XX:+ShowCodeDetailsInExceptionMessages, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dio.netty.allocator.numDirectArenas=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Dlog4j2.formatMsgNoLookups=true, -Djava.locale.providers=SPI,COMPAT, --add-opens=java.base/java.io=ALL-UNNAMED, -Djava.security.manager=allow, -XX:+UseG1GC, -Djava.io.tmpdir=/tmp/elasticsearch-8287321061376320899, -XX:+HeapDumpOnOutOfMemoryError, -XX:+ExitOnOutOfMemoryError, -XX:HeapDumpPath=data, -XX:ErrorFile=logs/hs_err_pid%p.log, -Xlog:gc*,gc+age=trace,safepoint:file=logs/gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Des.cgroups.hierarchy.override=/, -Xms512m, -Xmx512m, -XX:MaxDirectMemorySize=268435456, -XX:G1HeapRegionSize=4m, -XX:InitiatingHeapOccupancyPercent=30, -XX:G1ReservePercent=15, -Des.path.home=/usr/share/elasticsearch, -Des.path.conf=/usr/share/elasticsearch/config, -Des.distribution.flavor=default, -Des.distribution.type=docker, -Des.bundled_jdk=true]" }
   ___   _   __  __ _   _ _  _ ___   _      ___  ___ ___ ___    _ _____ ___
  / __| /_\ |  \/  | | | | \| |   \ /_\    / _ \| _ \ __| _ \  /_\_   _| __|
 | (__ / _ \| |\/| | |_| | .` | |) / _ \  | (_) |  _/ _||   / / _ \| | | _|
  \___/_/ \_\_|  |_|\___/|_|\_|___/_/ \_\  \___/|_| |___|_|_\/_/ \_\_| |___|

                               8.2.0-alpha4

2023-02-11 07:29:16.233  INFO 2 --- [           main] i.c.o.Application                        : Starting Application using Java 17.0.6 on 2b21fa62a8fd with PID 2 (/usr/local/operate/lib/operate-webapp-8.2.0-alpha4-exec.jar started by root in /usr/local/operate)
2023-02-11 07:29:16.277  INFO 2 --- [           main] i.c.o.Application                        : The following 1 profile is active: "auth"
2023-02-11 07:29:25.901  INFO 1 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'io.camunda.tasklist.webapp.security.CustomMethodSecurityExpressionHandler' of type [io.camunda.tasklist.webapp.security.CustomMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-02-11 07:29:25.904  INFO 1 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'io.camunda.tasklist.webapp.security.MethodSecurityConfig' of type [io.camunda.tasklist.webapp.security.MethodSecurityConfig$$EnhancerBySpringCGLIB$$6f9c6bbe] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-02-11 07:29:28.311  INFO 1 --- [           main] o.s.b.w.e.t.TomcatWebServer              : Tomcat initialized with port(s): 8080 (http)
2023-02-11 07:29:28.409  INFO 1 --- [           main] o.a.c.c.StandardService                  : Starting service [Tomcat]
2023-02-11 07:29:28.414  INFO 1 --- [           main] o.a.c.c.StandardEngine                   : Starting Servlet engine: [Apache Tomcat/9.0.69]
2023-02-11 07:29:29.479  INFO 1 --- [           main] o.a.c.c.C.[.[.[/]                        : Initializing Spring embedded WebApplicationContext
2023-02-11 07:29:29.485  INFO 1 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 15282 ms
{"type": "server", "timestamp": "2023-02-11T07:29:29,621Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [aggs-matrix-stats]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,622Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [analysis-common]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,625Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [constant-keyword]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,626Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [frozen-indices]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,629Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [ingest-common]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,640Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [ingest-geoip]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,696Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [ingest-user-agent]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,697Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [kibana]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,698Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [lang-expression]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,699Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [lang-mustache]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,700Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [lang-painless]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,701Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [legacy-geo]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,701Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [mapper-extras]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,702Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [mapper-version]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,703Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [parent-join]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,704Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [percolator]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,705Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [rank-eval]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,707Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [reindex]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,708Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [repositories-metering-api]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,709Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [repository-encrypted]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,709Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [repository-url]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,710Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [runtime-fields-common]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,712Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [search-business-rules]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,713Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [searchable-snapshots]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,715Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [snapshot-repo-test-kit]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,715Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [spatial]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,716Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [transform]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,718Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [transport-netty4]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,718Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [unsigned-long]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,718Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [vector-tile]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,719Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [vectors]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,719Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [wildcard]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,725Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-aggregate-metric]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,729Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-analytics]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,730Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-async]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,732Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-async-search]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,733Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-autoscaling]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,733Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-ccr]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,734Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-core]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,739Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-data-streams]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,744Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-deprecation]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,745Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-enrich]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,745Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-eql]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,748Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-fleet]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,748Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-graph]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,750Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-identity-provider]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,752Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-ilm]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,754Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-logstash]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,757Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-ml]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,761Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-monitoring]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,772Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-ql]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,774Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-rollup]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,779Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-security]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,785Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-shutdown]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,786Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-sql]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,786Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-stack]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,791Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-text-structure]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,791Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-voting-only-node]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,792Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "loaded module [x-pack-watcher]" }
{"type": "server", "timestamp": "2023-02-11T07:29:29,793Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "no plugins loaded" }
{"type": "server", "timestamp": "2023-02-11T07:29:30,036Z", "level": "INFO", "component": "o.e.e.NodeEnvironment", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "using [1] data paths, mounts [[/usr/share/elasticsearch/data (/dev/vda4)]], net usable_space [87.9gb], net total_space [99.4gb], types [xfs]" }
{"type": "server", "timestamp": "2023-02-11T07:29:30,048Z", "level": "INFO", "component": "o.e.e.NodeEnvironment", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "heap size [512mb], compressed ordinary object pointers [true]" }
{"type": "server", "timestamp": "2023-02-11T07:29:30,150Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "node name [eb070add9006], node ID [3otGV3axSaeDZgzgiFVFgA], cluster name [docker-cluster], roles [transform, data_frozen, master, remote_cluster_client, data, ml, data_content, data_hot, data_warm, data_cold, ingest]" }
2023-02-11 07:29:31.271  WARN 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Username and/or password for are empty. Basic authentication for elasticsearch is not used.
2023-02-11 07:29:35.139  INFO 2 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'io.camunda.operate.webapp.security.CustomMethodSecurityExpressionHandler' of type [io.camunda.operate.webapp.security.CustomMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-02-11 07:29:35.149  INFO 2 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'io.camunda.operate.webapp.security.MethodSecurityConfig' of type [io.camunda.operate.webapp.security.MethodSecurityConfig$$EnhancerBySpringCGLIB$$41d3ace1] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-02-11 07:29:37.688  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #1 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:29:37.723  INFO 2 --- [           main] o.s.b.w.e.t.TomcatWebServer              : Tomcat initialized with port(s): 8080 (http)
2023-02-11 07:29:37.827  INFO 2 --- [           main] o.a.c.h.Http11NioProtocol                : Initializing ProtocolHandler ["http-nio-8080"]
2023-02-11 07:29:37.829  INFO 2 --- [           main] o.a.c.c.StandardService                  : Starting service [Tomcat]
2023-02-11 07:29:37.838  INFO 2 --- [           main] o.a.c.c.StandardEngine                   : Starting Servlet engine: [Apache Tomcat/9.0.69]
2023-02-11 07:29:38.418  INFO 2 --- [           main] o.a.c.c.C.[.[.[/]                        : Initializing Spring embedded WebApplicationContext
2023-02-11 07:29:38.424  INFO 2 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 21706 ms
2023-02-11 07:29:39.919  WARN 2 --- [           main] o.s.b.a.e.EndpointId                     : Endpoint ID 'usage-metrics' contains invalid characters, please migrate to a valid format.
2023-02-11 07:29:40.707  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #2 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:29:41.184  INFO 2 --- [           main] i.c.o.WebappModuleConfiguration          : Starting module: webapp
2023-02-11 07:29:41.578  INFO 2 --- [           main] i.c.o.z.ZeebeConnector                   : Use plaintext connection to zeebe
2023-02-11 07:29:43.715  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #3 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:29:44.112  WARN 2 --- [           main] i.c.o.e.ElasticsearchConnector           : Username and/or password for are empty. Basic authentication for elasticsearch is not used.
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["info","plugins-service"],"pid":2,"message":"Plugin \"metricsEntities\" is disabled."}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["info","http","server","Preboot"],"pid":2,"message":"http server running at http://0.0.0.0:5601"}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["warning","config","deprecation"],"pid":2,"message":"Starting in 8.0, the Kibana logging format will be changing. This may affect you if you are doing any special handling of your Kibana logs, such as ingesting logs into Elasticsearch for further analysis. If you are using the new logging configuration, you are already receiving logs in both old and new formats, and the old format will simply be going away. If you are not yet using the new logging configuration, the log format will change upon upgrade to 8.0. Beginning in 8.0, the format of JSON logs will be ECS-compatible JSON, and the default pattern log format will be configurable with our new logging system. Please refer to the documentation for more information about the new logging format."}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["warning","config","deprecation"],"pid":2,"message":"The default mechanism for Reporting privileges will work differently in future versions, which will affect the behavior of this cluster. Set \"xpack.reporting.roles.enabled\" to \"false\" to adopt the future behavior before upgrading."}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["warning","config","deprecation"],"pid":2,"message":"User sessions will automatically time out after 8 hours of inactivity starting in 8.0. Override this value to change the timeout."}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["warning","config","deprecation"],"pid":2,"message":"Users are automatically required to log in again after 30 days starting in 8.0. Override this value to change the timeout."}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["info","plugins-system","standard"],"pid":2,"message":"Setting up [113] plugins: [translations,licensing,globalSearch,globalSearchProviders,features,licenseApiGuard,code,usageCollection,xpackLegacy,taskManager,telemetryCollectionManager,telemetryCollectionXpack,kibanaUsageCollection,share,embeddable,uiActionsEnhanced,screenshotMode,banners,telemetry,newsfeed,mapsEms,mapsLegacy,kibanaLegacy,fieldFormats,expressions,dataViews,charts,esUiShared,bfetch,data,savedObjects,presentationUtil,expressionShape,expressionRevealImage,expressionRepeatImage,expressionMetric,expressionImage,customIntegrations,home,searchprofiler,painlessLab,grokdebugger,management,watcher,licenseManagement,advancedSettings,spaces,security,savedObjectsTagging,reporting,canvas,lists,ingestPipelines,fileUpload,encryptedSavedObjects,dataEnhanced,cloud,snapshotRestore,eventLog,actions,alerting,triggersActionsUi,transform,stackAlerts,ruleRegistry,visualizations,visTypeXy,visTypeVislib,visTypeVega,visTypeTimelion,visTypeTagcloud,visTypeTable,visTypePie,visTypeMetric,visTypeMarkdown,tileMap,regionMap,expressionTagcloud,expressionMetricVis,console,graph,fleet,indexManagement,remoteClusters,crossClusterReplication,indexLifecycleManagement,dashboard,maps,dashboardMode,dashboardEnhanced,visualize,visTypeTimeseries,rollup,indexPatternFieldEditor,lens,cases,timelines,discover,osquery,observability,discoverEnhanced,dataVisualizer,ml,uptime,securitySolution,infra,upgradeAssistant,monitoring,logstash,enterpriseSearch,apm,savedObjectsManagement,indexPatternManagement]"}
{"type":"log","@timestamp":"2023-02-11T07:29:44+00:00","tags":["info","plugins","taskManager"],"pid":2,"message":"TaskManager is identified by the Kibana UUID: bcd4e111-10d1-44a7-bd16-da5565afb4b5"}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","security","config"],"pid":2,"message":"Generating a random key for xpack.security.encryptionKey. To prevent sessions from being invalidated on restart, please set xpack.security.encryptionKey in the kibana.yml or use the bin/kibana-encryption-keys command."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","security","config"],"pid":2,"message":"Session cookies will be transmitted over insecure connections. This is not recommended."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","security","config"],"pid":2,"message":"Generating a random key for xpack.security.encryptionKey. To prevent sessions from being invalidated on restart, please set xpack.security.encryptionKey in the kibana.yml or use the bin/kibana-encryption-keys command."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","security","config"],"pid":2,"message":"Session cookies will be transmitted over insecure connections. This is not recommended."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","reporting","config"],"pid":2,"message":"Generating a random key for xpack.reporting.encryptionKey. To prevent sessions from being invalidated on restart, please set xpack.reporting.encryptionKey in the kibana.yml or use the bin/kibana-encryption-keys command."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","encryptedSavedObjects"],"pid":2,"message":"Saved objects encryption key is not set. This will severely limit Kibana functionality. Please set xpack.encryptedSavedObjects.encryptionKey in the kibana.yml or use the bin/kibana-encryption-keys command."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","actions"],"pid":2,"message":"APIs are disabled because the Encrypted Saved Objects plugin is missing encryption key. Please set xpack.encryptedSavedObjects.encryptionKey in the kibana.yml or use the bin/kibana-encryption-keys command."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["warning","plugins","alerting"],"pid":2,"message":"APIs are disabled because the Encrypted Saved Objects plugin is missing encryption key. Please set xpack.encryptedSavedObjects.encryptionKey in the kibana.yml or use the bin/kibana-encryption-keys command."}
{"type":"log","@timestamp":"2023-02-11T07:29:45+00:00","tags":["info","plugins","ruleRegistry"],"pid":2,"message":"Installing common resources shared between all indices"}
2023-02-11 07:29:46.730  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #4 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:29:47.616  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
{"type":"log","@timestamp":"2023-02-11T07:29:47+00:00","tags":["info","plugins","reporting","config"],"pid":2,"message":"Chromium sandbox provides an additional layer of protection, and is supported for Linux Ubuntu 20.04 OS. Automatically enabling Chromium sandbox."}
2023-02-11 07:29:49.793  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #5 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:29:53.409  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #6 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
{"type": "server", "timestamp": "2023-02-11T07:29:55,710Z", "level": "INFO", "component": "o.e.x.m.p.l.CppLogMessageHandler", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "[controller/178] [Main.cc@122] controller (64 bit): Version 7.17.5 (Build 6070d498c77671) Copyright (c) 2022 Elasticsearch BV" }
{"type": "server", "timestamp": "2023-02-11T07:30:10,638Z", "level": "INFO", "component": "o.e.i.g.ConfigDatabases", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "initialized default databases [[GeoLite2-Country.mmdb, GeoLite2-City.mmdb, GeoLite2-ASN.mmdb]], config databases [[]] and watching [/usr/share/elasticsearch/config/ingest-geoip] for changes" }
{"type": "server", "timestamp": "2023-02-11T07:30:10,819Z", "level": "INFO", "component": "o.e.i.g.DatabaseNodeService", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "initialized database registry, using geoip-databases directory [/tmp/elasticsearch-8287321061376320899/geoip-databases/3otGV3axSaeDZgzgiFVFgA]" }
{"type": "server", "timestamp": "2023-02-11T07:31:20,100Z", "level": "WARN", "component": "o.e.t.ThreadPool", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "execution of [ReschedulingRunnable{runnable=org.elasticsearch.watcher.ResourceWatcherService$ResourceMonitor@38428625, interval=5s}] took [5167ms] which is above the warn threshold of [5000ms]" }
{"type": "server", "timestamp": "2023-02-11T07:31:48,915Z", "level": "WARN", "component": "o.e.t.ThreadPool", "cluster.name": "docker-cluster", "node.name": "eb070add9006", "message": "execution of [ReschedulingRunnable{runnable=org.elasticsearch.watcher.ResourceWatcherService$ResourceMonitor@38428625, interval=5s}] took [5510ms] which is above the warn threshold of [5000ms]" }
2023-02-11 07:32:02.101  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:05.044  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #7 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:05.114  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:08.067  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #8 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:08.117  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
{"type":"log","@timestamp":"2023-02-11T07:32:08+00:00","tags":["error","elasticsearch-service"],"pid":2,"message":"Unable to retrieve version information from Elasticsearch nodes. connect ECONNREFUSED 10.89.3.2:9200"}
2023-02-11 07:32:11.102  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #9 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:11.149  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:14.153  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:14.154  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #10 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:18.777  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #11 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:18.818  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:21.819  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #12 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:21.849  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
exit code: 137
2023-02-11 07:32:28.933  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #13 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:40.474  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
  ______  ______   ______   ____    ______     ____    _____     ____    _  __  ______   _____
 |___  / |  ____| |  ____| |  _ \  |  ____|   |  _ \  |  __ \   / __ \  | |/ / |  ____| |  __ \
    / /  | |__    | |__    | |_) | | |__      | |_) | | |__) | | |  | | | ' /  | |__    | |__) |
   / /   |  __|   |  __|   |  _ <  |  __|     |  _ <  |  _  /  | |  | | |  <   |  __|   |  _  /
  / /__  | |____  | |____  | |_) | | |____    | |_) | | | \ \  | |__| | | . \  | |____  | | \ \
 /_____| |______| |______| |____/  |______|   |____/  |_|  \_\  \____/  |_|\_\ |______| |_|  \_\

2023-02-11 07:32:43.481  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:43.491  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #14 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:43.571 [] [main] INFO
      io.camunda.zeebe.broker.StandaloneBroker - Starting StandaloneBroker v8.1.7 using Java 17.0.5 on 5e7e07a28978 with PID 3 (/usr/local/zeebe/lib/camunda-zeebe-8.1.7.jar started by root in /usr/local/zeebe)
2023-02-11 07:32:43.771 [] [main] INFO
      io.camunda.zeebe.broker.StandaloneBroker - The following 1 profile is active: "broker"
2023-02-11 07:32:46.493  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #15 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:32:46.524  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:32:49.593  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #16 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:33:20.251  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #17 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:33:32.308  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:33:56.753  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:33:59.686  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #18 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:33:59.762  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:34:02.692  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #19 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-11 07:34:02.768  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-11 07:34:05.758  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #20 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];

akkie commented 1 year ago

I run zeebe also on a M1 Mac and for me the configured Elastic Search version worked. What was the reason for you to change the Elastic Search version? Whas there an error?

berndverst commented 1 year ago

I run zeebe also on a M1 Mac and for me the configured Elastic Search version worked. What was the reason for you to change the Elastic Search version? Whas there an error?

The original version does seem to work. The issue is that Elastic Search requires running the container engine with root. I used podman. I fixed it with podman machine stop && podman machine edit --rootful=true && podman machine start

Now using 1.7.5 for Elastic Search and 8.2.0-alpha4 seems to work.

Going to try this again...

EDIT: I'm still seeing

{"type":"log","@timestamp":"2023-02-14T20:00:48+00:00","tags":["info","plugins","ruleRegistry"],"pid":2,"message":"Installing common resources shared between all indices"}
2023-02-14 20:00:49.929  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-14 20:00:50.352  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #10 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
{"type":"log","@timestamp":"2023-02-14T20:00:50+00:00","tags":["info","plugins","reporting","config"],"pid":2,"message":"Chromium sandbox provides an additional layer of protection, and is supported for Linux Ubuntu 20.04 OS. Automatically enabling Chromium sandbox."}
2023-02-14 20:00:52.940  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
{"type":"log","@timestamp":"2023-02-14T20:00:53+00:00","tags":["error","elasticsearch-service"],"pid":2,"message":"Unable to retrieve version information from Elasticsearch nodes. connect ECONNREFUSED 10.89.0.2:9200"}
2023-02-14 20:00:53.355  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #11 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:00:56.430  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #12 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:00:56.471  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-14 20:01:01.100  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #13 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:01:01.124  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-14 20:01:05.314  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #14 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:01:05.347  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
exit code: 137
2023-02-14 20:01:08.532  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #15 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:01:08.559  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-14 20:01:12.270  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #16 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:01:12.316  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused
2023-02-14 20:01:15.306  INFO 1 --- [           main] i.c.t.e.ElasticsearchConnector           : Retrying #17 connect to Elasticsearch at http://elasticsearch:9200 due to ElasticsearchException[java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused]; nested: ExecutionException[java.net.ConnectException: Connection refused]; nested: ConnectException[Connection refused];
2023-02-14 20:01:15.321  WARN 2 --- [           main] i.c.o.u.RetryOperation                   : java.util.concurrent.ExecutionException: java.net.ConnectException: Connection refused

berndverst commented 1 year ago

It seems this just doesn't work with podman. I reinstalled docker and it's fine. Still doesn't explain my issues on Linux though (running Docker there).

berndverst commented 1 year ago

We have provided an example with which you can reproduce the issue: https://github.com/PlanBGmbH/zeebe-dapr-example

Steps to reproduce:

Checkout Zeebe docker compose: git clone https://github.com/camunda/camunda-platform.git (if you run it on a ARM Mac, then the versions for Zeebe, Operate and Tasklist needs to be changed to 8.2.0-alpha4, connectors needs to be removed)

Run Zeebe: docker compose -f camunda-platform/docker-compose-core.yaml up

Clone the example repo: git clone https://github.com/PlanBGmbH/zeebe-dapr-example.git

Run the service: dotnet run --project "./zeebe-dapr-example/Zeebe.Worker/Zeebe.Worker.csproj"

Deploy the process and instantiate the process (see below)

Open operate and look at the process: http://localhost:8081 (demo, demo)

There are files with the extension .http in the example project. These files can be executed with the RESt Client VSCode extension: https://marketplace.visualstudio.com/items?itemName=humao.rest-client

The deploy-process.http and the first request from the create-instance.http file needs to be executed

To provide more clarity:

For M1 Mac the docker-compose-core.yaml should be

# While the Docker images themselves are supported for production usage,
# this docker-compose.yaml is designed to be used by developers to run
# an environment locally. It is not designed to be used in production.
# We recommend to use Kubernetes in production with our Helm Charts:
# https://docs.camunda.io/docs/self-managed/platform-deployment/kubernetes-helm/
# For local development, we recommend using KIND instead of `docker-compose`:
# https://docs.camunda.io/docs/self-managed/platform-deployment/helm-kubernetes/guides/local-kubernetes-cluster/

# This is a lightweight configuration with Zeebe, Operate, Tasklist, and Elasticsearch
# See docker-compose.yml for a configuration that also includes Optimize, Identity, and Keycloak.

services:

  zeebe: # https://docs.camunda.io/docs/self-managed/platform-deployment/docker/#zeebe
    image: camunda/zeebe:${CAMUNDA_PLATFORM_VERSION:-8.2.0-alpha4}
    container_name: zeebe
    ports:
      - "26500:26500"
      - "9600:9600"
    environment: # https://docs.camunda.io/docs/self-managed/zeebe-deployment/configuration/environment-variables/
      - ZEEBE_BROKER_EXPORTERS_ELASTICSEARCH_CLASSNAME=io.camunda.zeebe.exporter.ElasticsearchExporter
      - ZEEBE_BROKER_EXPORTERS_ELASTICSEARCH_ARGS_URL=http://elasticsearch:9200
      - ZEEBE_BROKER_EXPORTERS_ELASTICSEARCH_ARGS_BULK_SIZE=1
      # allow running with low disk space
      - ZEEBE_BROKER_DATA_DISKUSAGECOMMANDWATERMARK=0.998
      - ZEEBE_BROKER_DATA_DISKUSAGEREPLICATIONWATERMARK=0.999
      - "JAVA_TOOL_OPTIONS=-Xms512m -Xmx512m"
    restart: always
    volumes:
      - zeebe:/usr/local/zeebe/data
    networks:
      - camunda-platform
    depends_on:
      - elasticsearch

  operate: # https://docs.camunda.io/docs/self-managed/platform-deployment/docker/#operate
    image: camunda/operate:${CAMUNDA_PLATFORM_VERSION:-8.2.0-alpha4}
    container_name: operate
    ports:
      - "8081:8080"
    environment: # https://docs.camunda.io/docs/self-managed/operate-deployment/configuration/
      - CAMUNDA_OPERATE_ZEEBE_GATEWAYADDRESS=zeebe:26500
      - CAMUNDA_OPERATE_ELASTICSEARCH_URL=http://elasticsearch:9200
      - CAMUNDA_OPERATE_ZEEBEELASTICSEARCH_URL=http://elasticsearch:9200
    networks:
      - camunda-platform
    depends_on:
      - zeebe
      - elasticsearch

  tasklist: # https://docs.camunda.io/docs/self-managed/platform-deployment/docker/#tasklist
    image: camunda/tasklist:${CAMUNDA_PLATFORM_VERSION:-8.2.0-alpha4}
    container_name: tasklist
    ports:
      - "8082:8080"
    environment: # https://docs.camunda.io/docs/self-managed/tasklist-deployment/configuration/
      - CAMUNDA_TASKLIST_ZEEBE_GATEWAYADDRESS=zeebe:26500
      - CAMUNDA_TASKLIST_ELASTICSEARCH_URL=http://elasticsearch:9200
      - CAMUNDA_TASKLIST_ZEEBEELASTICSEARCH_URL=http://elasticsearch:9200
    networks:
      - camunda-platform
    depends_on:
      - zeebe
      - elasticsearch

  elasticsearch: # https://hub.docker.com/_/elasticsearch
    image: docker.elastic.co/elasticsearch/elasticsearch:${ELASTIC_VERSION:-7.17.5}
    container_name: elasticsearch
    ports:
      - "9200:9200"
      - "9300:9300"
    environment:
      - bootstrap.memory_lock=true
      - discovery.type=single-node
      - xpack.security.enabled=false
      # allow running with low disk space
      - cluster.routing.allocation.disk.threshold_enabled=false
      - "ES_JAVA_OPTS=-Xms512m -Xmx512m"
    ulimits:
      memlock:
        soft: -1
        hard: -1
    restart: always
    healthcheck:
      test: [ "CMD-SHELL", "curl -f http://localhost:9200/_cat/health | grep -q green" ]
      interval: 30s
      timeout: 5s
      retries: 3
    volumes:
      - elastic:/usr/share/elasticsearch/data
    networks:
      - camunda-platform

  kibana:
    image: docker.elastic.co/kibana/kibana:${ELASTIC_VERSION:-7.17.0}
    container_name: kibana
    ports:
      - 5601:5601
    volumes:
      - kibana:/usr/share/kibana/data
    networks:
      - camunda-platform
    depends_on:
      - elasticsearch
    profiles:
      - kibana

volumes:
  zeebe:
  elastic:
  kibana:

networks:
  camunda-platform:

To run the Dot Net app you need DotNet Core Runtime 6.0 installed.

Once the app is running deploy the Zeebe workflow (a one time operation) like so:

curl -F fileName="process.bpmn" -F fileContent=@process.bpmn http://localhost:5001/v1.0/invoke/zeebe-worker/method/command/deploy-process

Now use your tool of choice to make the following JSON POST request:

POST http://localhost:5001/v1.0/invoke/zeebe-worker/method/command/create-instance
Content-Type: application/json

{
  "bpmnProcessId": "zeebe-test",
  "variables": {
    "operator": "+",
    "firstOperand": "412",
    "secondOperand": "20"
  }
}

In the operator dashboard at localhost:8081 (user demo, pass demo) you will see the zeebe-test workflow to have created a new run. Clicking on this shows the test succeeding or failing.

Here are my findings: With Dapr 1.9.6 this always succeeds. With Dapr 1.9.6 + upgraded Zeebe Client to 8.1.6 (latest) this also works. With Dapr 1.10-rc6 (Zeebe 8.1.6) this fails. With Dapr 1.10-rc8 (Zeebe 8.0.11) this fails. With Dapr 1.10-rc8 and Zeebe downgraded to 8.0.4 (same as original 1.9.6) this fails.

However, the failure is not that process variables are not stored.

Instead the failure is that the workflow suddenly cannot inject / process / find the result variable which isn't part of the request payload.

If you manually add result to the list of variables the workflow succeeds! (But the result is not updated)

It is not clear to me how this result variable is actually added by Zeebe (the server). It's also not clear what is different between 1.9 and 1.10 as there are no code changes to the Zeebe component at all between these versions.

The process variables do appear to be stored, but the failure is a different one.

berndverst commented 1 year ago

Using good old git bisect and building tons of Dapr versions manually, then going through the steps here we have now found the issue is caused by the following PR in the Dapr Runtime.

https://github.com/dapr/dapr/pull/5648

akkie commented 1 year ago

@berndverst @yaron2 I can confirm that the issue is fixed with Dapr 1.10.0-rc.9. Many thanks for the quick fix

I will have a look regarding the certification tests

fabistb commented 1 year ago

@berndverst , @yaron2 , I can also confirm that also on the cluster everything works. Thanks for the fix and the support!

dapr / components-contrib