Skip to content
This repository was archived by the owner on Dec 3, 2024. It is now read-only.
This repository was archived by the owner on Dec 3, 2024. It is now read-only.

tx-sender falil and restart container - 08100@broker.sarama: 24000@: 24000@: job status was updated since user request was sent\n\n" #69

@modanezi

Description

@modanezi

Good afternoon, I have a problem with my orchestrate and I can't identify where it is when I make a transaction

I get the error in tx-sender after receive first message in kakfa , it seems like it tries to remove the message from Kafka and fails.....

Command to start sender...

/orchestrate/build/bin/./orchestrate tx-sender run --kafka-url 172.30.52.79:9092 --api-url http://orchestrate-api.corp:80 --redis-port 6379 --redis-host 172.30.55.36 --log-level trace --key-manager-url https://qkm.dev.corp --metrics-modules disabled --key-manager-tls-skip-verify true --kafka-consumers 1 --kafka-tls-insecure-skip-verify --topic-tx-sender topic-tx-sender

in orchestrate TX-SENDER-RUN i receive this in log...

time="2023-12-13T16:37:09Z" level=debug msg="(entrypoint): switched tcp router" name=app
time="2023-12-13T16:37:09Z" level=debug msg="(broker.sarama.producer): Connected to broker at dab-kafka-1:9092 (registered as #1)\n"
time="2023-12-13T16:37:17Z" level=debug msg="(broker.sarama.producer): client/coordinator requesting coordinator for consumergroup group-sender from 172.30.52.79:9092\n"
time="2023-12-13T16:37:17Z" level=debug msg="(broker.sarama.producer): client/coordinator coordinator for consumergroup group-sender is #1 (dab-kafka-1:9092)\n"
time="2023-12-13T16:37:17Z" level=info msg="(service.kafka-consumer): ready to consume messages" claims="map[topic-tx-sender:[0]]" consumer=c-0 kafka.generation_id=2 kafka.member_id=sarama-orchestrate-d2d3fa4f-2fd6-4f54-a804-f52d47905941
time="2023-12-13T16:37:17Z" level=debug msg="(broker.sarama.producer): consumer/broker/1 added subscription to topic-tx-sender/0\n"
time="2023-12-13T16:37:17Z" level=info msg="(service.kafka-consumer): started consuming claims loop" consumer=c-0
time="2023-12-13T16:38:11Z" level=debug msg="(service.kafka-consumer): message consumed" consumer=c-0 envelope_id=77a67166-b353-49be-b82a-d01cbdb1d75f timestamp="2023-12-13 16:38:11.11 +0000 UTC"
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.craft-transaction): skip gas dynamic fee. Zero base fee is not allowed" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.craft-transaction): crafted gas price" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id= value=0x3b9aca00
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.craft-transaction): crafted gas estimation" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id= value=0xc00124a66
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.craft-transaction): crafted transaction nonce" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id= value=0xc000e358
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c one_time_key=false owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id= tx_hash=0xd1b3269b45af21a14eb9ba8e74e8e1e72f93781171a7dea1932afe
time="2023-12-13T16:38:11Z" level=debug msg="(use-cases.send-eth-tx): job status was updated successfully" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f status=PENDING tenant_id=
time="2023-12-13T16:38:11Z" level=debug msg="(nonce-manager): increment account nonce value" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c last_sent=3 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:11Z" level=info msg="(use-cases.send-eth-tx): ethereum transaction job was sent successfully" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:11Z" level=debug msg="(service.kafka-consumer): job message has been processed" consumer=c-0 job=f903d0c5-bfd4-4cdb-b313-451d2ced776c schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:12Z" level=debug msg="(service.kafka-consumer): message consumed" consumer=c-0 envelope_id=77a67166-b353-49be-b82a-d01cbdb1d75f timestamp="2023-12-13 16:38:11.179 +0000 UTC"
time="2023-12-13T16:38:12Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:12Z" level=debug msg="(nonce-manager): calibrating nonce" consumer=c-0 job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= pending_nonce=0 schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:12Z" level=debug msg="(use-cases.craft-transaction): crafted transaction nonce" consumer=c-0 job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id= value=0xc0012b280
time="2023-12-13T16:38:12Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=a9a54897-3aee-460c-9855-3ee485980ea8 one_time_key=false owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id= tx_hash=0x5c183bbb25cd26b4f801987761fcf627f9704d2d643c83a98fc436dec495497
time="2023-12-13T16:38:12Z" level=warning msg="(use-cases.send-eth-tx): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:13Z" level=warning msg="(use-cases.send-eth-tx): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:14Z" level=warning msg="(use-cases.send-eth-tx): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:15Z" level=warning msg="(use-cases.send-eth-tx): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:16Z" level=warning msg="(use-cases.send-eth-tx): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f tenant_id=
time="2023-12-13T16:38:17Z" level=error msg="(use-cases.send-eth-tx): failed to update job status" consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 owner_id= schedule_uuid=77a67166-b353-49be-b82a-d01cbdb1d75f status=PENDING tenant_id=
time="2023-12-13T16:38:17Z" level=debug msg="(service.kafka-consumer): sending envelope" consumer=c-0 envelope_id=77a67166-b353-49be-b82a-d01cbdb1d75f topic=topic-tx-recover
time="2023-12-13T16:38:17Z" level=debug msg="(broker.sarama.producer): producer/broker/1 starting up\n"
time="2023-12-13T16:38:17Z" level=debug msg="(broker.sarama.producer): producer/broker/1 state change to [open] on topic-tx-recover/0\n"
time="2023-12-13T16:38:17Z" level=debug msg="(broker.sarama.producer): Connected to broker at dab-kafka-1:9092 (registered as #1)\n"
time="2023-12-13T16:38:17Z" level=info msg="(service.kafka-consumer): envelope successfully sent" consumer=c-0 envelope_id=77a67166-b353-49be-b82a-d01cbdb1d75f offset=1 partition=0 topic=topic-tx-recover
time="2023-12-13T16:38:17Z" level=warning msg="(service.kafka-consumer): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:18Z" level=warning msg="(service.kafka-consumer): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:19Z" level=warning msg="(service.kafka-consumer): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:21Z" level=warning msg="(service.kafka-consumer): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:22Z" level=warning msg="(service.kafka-consumer): http call has failed, retrying in [1s]..." consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:23Z" level=error msg="(service.kafka-consumer): failed to update job status" consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f status=FAILED
time="2023-12-13T16:38:23Z" level=error msg="(service.kafka-consumer): error processing message" consumer=c-0 error="24000@: 24000@: job status was updated since user request was sent" job=a9a54897-3aee-460c-9855-3ee485980ea8 schedule=77a67166-b353-49be-b82a-d01cbdb1d75f
time="2023-12-13T16:38:23Z" level=debug msg="(broker.sarama.producer): consumer/broker/1 closed dead subscription to topic-tx-sender/0\n"
time="2023-12-13T16:38:23Z" level=info msg="(service.kafka-consumer): all claims consumed" consumer=c-0
time="2023-12-13T16:38:23Z" level=debug msg="(service.kafka-consumer): canceling context" consumer=c-0
time="2023-12-13T16:38:23Z" level=debug msg="(broker.sarama.producer): loop check partition number coroutine will exit, topics [topic-tx-sender]"
time="2023-12-13T16:38:23Z" level=error msg="(application): exits with errors" error="1 error occurred:\n\t* 08100@broker.sarama: 24000@: 24000@: job status was updated since user request was sent\n\n"
time="2023-12-13T16:38:23Z" level=debug msg="(application): shutting down..."
time="2023-12-13T16:38:23Z" level=info msg="(tcp): shutting down..." entrypoint=metrics
time="2023-12-13T16:38:23Z" level=info msg="(tcp): shutting down..." entrypoint=app
time="2023-12-13T16:38:23Z" level=info msg="(application): gracefully shutted down" error=""
Error: 1 error occurred:
* 08100@broker.sarama: 24000@: 24000@: job status was updated since user request was sent

time="2023-12-13T16:38:23Z" level=fatal msg="main: execution failed" error="1 error occurred:\n\t* 08100@broker.sarama: 24000@: 24000@: job status was updated since user request was sent\n\n"

in orchestrate API RUN y recive this in log

start API
/orchestrate/build/bin/./orchestrate api run --rest-port 80 --kafka-url 172.30.52.79:9092 --db-password postgres --db-host 10.0.78 --db-port 50008 --db-database orchestrate --log-level error --metrics-modules disabled --accesslog-enabled --key-manager-url https://qkm.dev.corp --key-manager-tls-skip-verify --kafka-tls-insecure-skip-verify --proxy-max-idle-connections-per-host 100 --topic-tx-sender topic-tx-sender

time="2023-12-13T19:40:21Z" level=info msg="(broker.sarama.producer): client ready" broker="map[1:dab-kafka-1:9092]" host="[172.30.52.79:9092]"
time="2023-12-13T19:40:21Z" level=info msg="(broker.sarama.producer): producer ready"
time="2023-12-13T19:40:21Z" level=info msg="(ethclient.rpc): ready"
time="2023-12-13T19:40:21Z" level=info msg="(quorum-key-manager.client): client ready" url="https://qkm.dev.corp"
time="2023-12-13T19:40:21Z" level=info msg="(database.postgres): creating database connector" dial.timeout=5s idle.check-frequency=1m0s idle.timeout=5m0s pool.size=80 pool.timeout=30s user=postgresdba
time="2023-12-13T19:43:20Z" level=error msg="(use-cases.update-job): job status was updated since user request was sent" job=e2f558f1-ef74-476e-9f5c-9c9262c0a24c next_status=PENDING status=STARTED
time="2023-12-13T19:43:20Z" level=error msg=Conflict client.addr="10.130.42.1:46884" client.host=10.130.42.1 client.port=46884 client.user.name=- downstream_Content-Type=application/json downstream_X-Content-Type-Options=nosniff http.request.body.bytes=617 http.request.count=137 http.request.method=PATCH http.request.protocol=HTTP/1.1 http.request.retry_attempts=0 http.response.bytes=86 http.response.status_code=409 process.overhead=66.059629ms process.start="2023-12-13 19:43:19.949574049 +0000 UTC" process.start_local="2023-12-13 19:43:19.949574049 +0000 UTC" process.uptime=66.059629ms request_Accept-Encoding=gzip request_Content-Length=617 request_Forwarded="for=172.16.242.34;host=orchestrate-api-.paas.br.dev.corp;proto=http" request_User-Agent=Go-http-client/1.1 request_X-Forwarded-Host=orchestrate-api-.paas.br.dev.corp request_X-Forwarded-Port=80 request_X-Forwarded-Proto=http request_X-Forwarded-Server=orchestrate-api-80-6687b74bc-bzqcc request_X-Real-Ip=10.130.42.1 type=accesslog url.domain=orchestrate-api.corp url.full=orchestrate-api.corp url.path=/jobs/e2f558f1-ef74-476e-9f5c-9c9262c0a24c url.port=- url.scheme=http

time="2023-12-13T19:43:21Z" level=error msg="(use-cases.update-job): job status was updated since user request was sent" job=e2f558f1-ef74-476e-9f5c-9c9262c0a24c next_status=PENDING status=STARTED
time="2023-12-13T19:43:21Z" level=error msg=Conflict client.addr="10.129.42.1:57108" client.host=10.129.42.1 client.port=57108 client.user.name=- downstream_Content-Type=application/json downstream_X-Content-Type-Options=nosniff http.request.body.bytes=617 http.request.count=138 http.request.method=PATCH http.request.protocol=HTTP/1.1 http.request.retry_attempts=0 http.response.bytes=86 http.response.status_code=409 process.overhead=66.589108ms process.start="2023-12-13 19:43:21.02330125 +0000 UTC" process.start_local="2023-12-13 19:43:21.02330125 +0000 UTC" process.uptime=66.589108ms request_Accept-Encoding=gzip request_Content-Length=617 request_Forwarded="for=172.16.242.34;host=orchestrate-api.corp;proto=http" request_User-Agent=Go-http-client/1.1 request_X-Forwarded-Host=orchestrate-api.corp request_X-Forwarded-Port=80 request_X-Forwarded-Proto=http request_X-Forwarded-Server=orchestrate-api-80-6687b74bc-bzqcc request_X-Real-Ip=10.129.42.1 type=accesslog url.domain=orchestrate-api.corp url.full=orchestrate-api.corp url.path=/jobs/e2f558f1-ef74-476e-9f5c-9c9262c0a24c url.port=- url.scheme=http

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions