search

safe-global / safe-infrastructure

One `docker-compose.yml` file to rule them all
MIT License
56 stars 92 forks source link

Indexing of signed transaction taking 1 hour #94

Closed skimaharvey closed 1 year ago

skimaharvey commented 1 year ago

set up the safe-infrastructure with a local node.

everything is working fine however when creating a signed transaction. Indexing is very slow (around 1 hour) any idea what is happening? (even though when I check the transaction API, I can find my transaction there)

Could it be related to my webhook not being appropriately set http://nginx:8000/cgw/v1/chains/4201/hooks/events where 4201 is the chainId and my authorization is Basic some_random_token (have not changed it in the .env files)?

I tried looking at the log of the webhook, when the transaction is confirmed by my wallet:

2023-05-15 10:03:46,383 [INFO] [19466a2c/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[19466a2c-25d9-414d-8696-7ae56f4b0bbb] succeeded in 0.03691449999951146s: (0, 0)
2023-05-15 10:03:46,394 [INFO] [cc00d0c0/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[cc00d0c0-cd06-4e03-95fd-e81cf95778cf] succeeded in 0.03862212500007445s: (0, 0)
2023-05-15 10:03:46,405 [INFO] [f44d68a5/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[f44d68a5-4764-4d41-9ee4-6bab4c1ff5b4] succeeded in 0.010306166000191297s: (0, 0)
2023-05-15 10:03:46,413 [INFO] [04bbdd4e/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[04bbdd4e-7165-4fa1-8448-a333091237db] succeeded in 0.01722387500012701s: (0, 0)
2023-05-15 10:03:46,465 [INFO] [e3125c97/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[e3125c97-3974-438f-ac9c-7eed86260b27] succeeded in 0.006571916000211786s: (0, 0)

and this is what is happening at the client gateway level

2023-05-15 10:03:46,383 [INFO] [19466a2c/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[19466a2c-25d9-414d-8696-7ae56f4b0bbb] succeeded in 0.03691449999951146s: (0, 0)
2023-05-15 10:03:46,394 [INFO] [cc00d0c0/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[cc00d0c0-cd06-4e03-95fd-e81cf95778cf] succeeded in 0.03862212500007445s: (0, 0)
2023-05-15 10:03:46,405 [INFO] [f44d68a5/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[f44d68a5-4764-4d41-9ee4-6bab4c1ff5b4] succeeded in 0.010306166000191297s: (0, 0)
2023-05-15 10:03:46,413 [INFO] [04bbdd4e/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[04bbdd4e-7165-4fa1-8448-a333091237db] succeeded in 0.01722387500012701s: (0, 0)
2023-05-15 10:03:46,465 [INFO] [e3125c97/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[e3125c97-3974-438f-ac9c-7eed86260b27] succeeded in 0.006571916000211786s: (0, 0)
Uxio0 commented 1 year ago

You are sharing the exact same logs for both services

skimaharvey commented 1 year ago

sorry here is the logs of the notification webhooks worker

2023-05-15 11:51:08,317 [INFO] [81ca00f9/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[81ca00f9-aaf8-43ea-8f54-f978963fe7e6] succeeded in 0.02407537500039325s: (0, 0)
2023-05-15 11:51:08,330 [INFO] [ef6e58d2/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[ef6e58d2-4d82-4612-9088-a022317e7f29] succeeded in 0.063068708001083s: (0, 0)
2023-05-15 11:51:08,348 [INFO] [b996a830/send_notification_owner_task] No need to send confirmation notification for safe=0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6 with threshold=1
2023-05-15 11:51:08,353 [INFO] [b996a830/send_notification_owner_task] Task safe_transaction_service.notifications.tasks.send_notification_owner_task[b996a830-c4e7-4719-90a0-e33844ed43c6] succeeded in 0.0211999580005795s: (0, 0)
2023-05-15 11:51:43,417 [INFO] [caefdf0b/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[caefdf0b-b191-4a5e-bc95-3f3cc206f766] succeeded in 0.012801625000065542s: (0, 0)
2023-05-15 11:51:43,421 [INFO] [b9b3bd79/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[b9b3bd79-1c37-4607-89ee-590f731376a3] succeeded in 0.019092250000539934s: (0, 0)
2023-05-15 11:51:43,432 [INFO] [df7d60e2/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[df7d60e2-c726-4635-9278-61c120015c56] succeeded in 0.009323332998974365s: (0, 0)
2023-05-15 11:51:43,439 [INFO] [b9b82676/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[b9b82676-37cc-4a21-8aa6-da7bcde40405] succeeded in 0.017426166999939596s: (0, 0)

Here the logs of the CGW 

[2023-05-15T11:51:18Z INFO  _] Response succeeded.
[2023-05-15T11:51:30Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6:
[2023-05-15T11:51:30Z INFO  _] Matched: (get_safe_info) GET /v1/chains/<chain_id>/safes/<safe_address>
[2023-05-15T11:51:30Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages:
[2023-05-15T11:51:30Z ERROR _] No matching routes for GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages.
[2023-05-15T11:51:30Z WARN  _] Responding with registered (not_found) 404 catcher.
[2023-05-15T11:51:30Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages::1::404::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages::4201::172.18.0.1
[2023-05-15T11:51:30Z INFO  _] Response succeeded.
[2023-05-15T11:51:30Z INFO  _] Outcome: Success
[2023-05-15T11:51:30Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>::5::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6::4201::172.18.0.1
[2023-05-15T11:51:30Z INFO  _] Response succeeded.
[2023-05-15T11:51:31Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false:
[2023-05-15T11:51:31Z INFO  _] Matched: (get_balances) GET /v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>
[2023-05-15T11:51:31Z INFO  _] Outcome: Success
[2023-05-15T11:51:31Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>::1::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false::4201::172.18.0.1
[2023-05-15T11:51:31Z INFO  _] Response succeeded.
[2023-05-15T11:51:46Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6:
[2023-05-15T11:51:46Z INFO  _] Matched: (get_safe_info) GET /v1/chains/<chain_id>/safes/<safe_address>
[2023-05-15T11:51:46Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false:
[2023-05-15T11:51:46Z INFO  _] Matched: (get_balances) GET /v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>
[2023-05-15T11:51:46Z INFO  _] Outcome: Success
[2023-05-15T11:51:46Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>::2::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false::4201::172.18.0.1
[2023-05-15T11:51:46Z INFO  _] Response succeeded.
[2023-05-15T11:51:46Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages:
[2023-05-15T11:51:46Z ERROR _] No matching routes for GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages.
[2023-05-15T11:51:46Z WARN  _] Responding with registered (not_found) 404 catcher.
[2023-05-15T11:51:46Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages::0::404::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages::4201::172.18.0.1
[2023-05-15T11:51:46Z INFO  _] Response succeeded.
[2023-05-15T11:51:46Z INFO  _] Outcome: Success
[2023-05-15T11:51:46Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>::9::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6::4201::172.18.0.1
[2023-05-15T11:51:46Z INFO  _] Response succeeded.
[2023-05-15T11:51:46Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false:
[2023-05-15T11:51:46Z INFO  _] Matched: (get_balances) GET /v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>
[2023-05-15T11:51:46Z INFO  _] Outcome: Success
[2023-05-15T11:51:46Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>::0::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false::4201::172.18.0.1
skimaharvey commented 1 year ago

Same info but with debug equals 1. for the webhook notifier: 

023-05-15 16:07:34,379 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffffa94db7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'e3c7dbe4-5487-4ce6-b081-210e26dfb91e', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'e3c7dbe4-5487-4ce6-b081-210e26dfb91e', 'shadow': None, 'eta': '2023-05-15T16:07:34.377660+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'parent_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'argsrepr': "('0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', {'address': '0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', 'type': 'INCOMING_ETHER', 'txHash': '0x07162d4f6afcddfb3772c75927a2db06e2de03f14a9ae4b68171527b3bece688', 'value': '2000000000000000', 'chainId': '-1'})", 'kwargsrepr': '{}', 'origin': 'gen1@e979e5b56343', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-15 16:07:34,389 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffffa94db7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', '81de5212-b561-41b6-ae8d-5868e4876295', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': '81de5212-b561-41b6-ae8d-5868e4876295', 'shadow': None, 'eta': '2023-05-15T16:07:34.380034+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'parent_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'type': 'OUTGOING_ETHER', 'txHash': '0x07162d4f6afcddfb3772c75927a2db06e2de03f14a9ae4b68171527b3bece688', 'value': '2000000000000000', 'chainId': '-1'})", 'kwargsrepr': '{}', 'origin': 'gen1@e979e5b56343', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-15 16:07:34,395 [DEBUG] [e3c7dbe4/send_notification_task] DB connection reused
2023-05-15 16:07:34,396 [DEBUG] [81de5212/send_notification_task] DB connection reused
2023-05-15 16:07:34,399 [DEBUG] [81de5212/send_notification_task] DB connection returned to the pool
2023-05-15 16:07:34,414 [INFO] [81de5212/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[81de5212-b561-41b6-ae8d-5868e4876295] succeeded in 0.022890874999575317s: (0, 0)
2023-05-15 16:07:34,414 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffffa94db7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', '0f5b535c-9c5a-4318-88b3-6ed53193750e', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': '0f5b535c-9c5a-4318-88b3-6ed53193750e', 'shadow': None, 'eta': '2023-05-15T16:07:34.415801+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'parent_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'type': 'OUTGOING_ETHER', 'txHash': '0x07162d4f6afcddfb3772c75927a2db06e2de03f14a9ae4b68171527b3bece688', 'value': '2000000000000000', 'chainId': '-1'})", 'kwargsrepr': '{}', 'origin': 'gen1@e979e5b56343', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-15 16:07:34,415 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffffa94db7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'f033aec3-b029-411f-aee9-a470f03ac1ae', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'f033aec3-b029-411f-aee9-a470f03ac1ae', 'shadow': None, 'eta': '2023-05-15T16:07:34.415132+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'parent_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'argsrepr': "('0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', {'address': '0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', 'type': 'INCOMING_ETHER', 'txHash': '0x07162d4f6afcddfb3772c75927a2db06e2de03f14a9ae4b68171527b3bece688', 'value': '2000000000000000', 'chainId': '-1'})", 'kwargsrepr': '{}', 'origin': 'gen1@e979e5b56343', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-15 16:07:34,415 [DEBUG] [e3c7dbe4/send_notification_task] DB connection returned to the pool
2023-05-15 16:07:34,421 [INFO] [e3c7dbe4/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[e3c7dbe4-5487-4ce6-b081-210e26dfb91e] succeeded in 0.039016292001178954s: (0, 0)
2023-05-15 16:07:34,424 [DEBUG] [0f5b535c/send_notification_task] DB connection reused
2023-05-15 16:07:34,424 [DEBUG] [f033aec3/send_notification_task] DB connection reused
2023-05-15 16:07:34,425 [DEBUG] [f033aec3/send_notification_task] DB connection returned to the pool
2023-05-15 16:07:34,430 [INFO] [f033aec3/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[f033aec3-b029-411f-aee9-a470f03ac1ae] succeeded in 0.007061207998049213s: (0, 0)
2023-05-15 16:07:34,430 [DEBUG] [0f5b535c/send_notification_task] DB connection returned to the pool
2023-05-15 16:07:34,435 [INFO] [0f5b535c/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[0f5b535c-9c5a-4318-88b3-6ed53193750e] succeeded in 0.013535041998693487s: (0, 0)
2023-05-15 16:07:34,559 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffffa94db7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'ebab26b3-4a61-4c0a-901d-0a4daf4c10ab', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'ebab26b3-4a61-4c0a-901d-0a4daf4c10ab', 'shadow': None, 'eta': '2023-05-15T16:07:34.552696+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'parent_id': '7a335f02-21e9-4b57-a914-1aefb1714384', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'safeTxHash': '0x168a956ad144a6deef5305f22b130bae05852448a36cb6d928f289983ed23d22', 'type': 'EXECUTED_MULTISIG_TRANSACTION', 'failed': 'false', 'txHash': '0x1d287501794ad7d98905f53ec171159dd7ec3f6703a264c6d9c5d2fa85f6e86c', 'chainId': '-1'})", 'kwargsrepr': '{}', 'origin': 'gen1@e979e5b56343', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding':... kwargs:{})
2023-05-15 16:07:34,561 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffffa94db7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'ad1344ad-bd14-4e84-9c49-6d7638a4b362', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'ad1344ad-bd14-4e84-9c49-6d7638a4b362', 'shadow': None, 'eta': '2023-05-15T16:07:34.559854+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '385df728-7f76-4721-a56b-b4049d26ef89', 'parent_id': '7a335f02-21e9-4b57-a914-1aefb1714384', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'safeTxHash': '0x625a49b64fa2e87b9022e5fee7c579389cbda43cc99fc95435775e36113dc0d6', 'type': 'EXECUTED_MULTISIG_TRANSACTION', 'failed': 'false', 'txHash': '0x07162d4f6afcddfb3772c75927a2db06e2de03f14a9ae4b68171527b3bece688', 'chainId': '-1'})", 'kwargsrepr': '{}', 'origin': 'gen1@e979e5b56343', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding':... kwargs:{})
2023-05-15 16:07:34,562 [DEBUG] [ebab26b3/send_notification_task] DB connection reused
2023-05-15 16:07:34,563 [DEBUG] [ad1344ad/send_notification_task] DB connection reused
2023-05-15 16:07:34,564 [DEBUG] [ebab26b3/send_notification_task] DB connection returned to the pool
2023-05-15 16:07:34,570 [INFO] [ebab26b3/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[ebab26b3-4a61-4c0a-901d-0a4daf4c10ab] succeeded in 0.010387124999397201s: (0, 0)
2023-05-15 16:07:34,570 [DEBUG] [ad1344ad/send_notification_task] DB connection returned to the pool
2023-05-15 16:07:34,574 [INFO] [ad1344ad/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[ad1344ad-bd14-4e84-9c49-6d7638a4b362] succeeded in 0.012979166000150144s: (0, 0)

I see a chainId 'chainId': '-1' could it be related? where is this chainId value coming from? btw I am using the your latest version of the safe-transaction service (pull from master and created an image) that includes this PR

Uxio0 commented 1 year ago

Yes, chainId not registered can be an issue, your chain should be registered on https://github.com/safe-global/safe-eth-py/blob/master/gnosis/eth/ethereum_network.py

Uxio0 commented 1 year ago

Please try to update the services, we are uploading to dockerhub this new version: https://github.com/safe-global/safe-transaction-service/releases/tag/v4.19.0

skimaharvey commented 1 year ago

Tried with 4.19.0 version for the safe-transaction-service This is the logs of the notification service:

2023-05-16 10:04:05,641 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffff82d9f7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'bfcd043b-ce90-42f3-8e88-b3f4a13c9f64', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'bfcd043b-ce90-42f3-8e88-b3f4a13c9f64', 'shadow': None, 'eta': '2023-05-16T10:04:05.638806+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'parent_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'argsrepr': "('0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', {'address': '0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', 'type': 'INCOMING_ETHER', 'txHash': '0xbb6f8ab2531b3d3de6df08ac2dbe58401f9679b2b87ddb146c3ecb9544e1e472', 'value': '100000000000000', 'chainId': '4201'})", 'kwargsrepr': '{}', 'origin': 'gen1@272bc8c4999e', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-16 10:04:05,641 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffff82d9f7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'a51c21e0-afbe-470b-ad37-8cc67c36b47e', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'a51c21e0-afbe-470b-ad37-8cc67c36b47e', 'shadow': None, 'eta': '2023-05-16T10:04:05.640111+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'parent_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'type': 'OUTGOING_ETHER', 'txHash': '0xbb6f8ab2531b3d3de6df08ac2dbe58401f9679b2b87ddb146c3ecb9544e1e472', 'value': '100000000000000', 'chainId': '4201'})", 'kwargsrepr': '{}', 'origin': 'gen1@272bc8c4999e', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-16 10:04:05,643 [DEBUG] [bfcd043b/send_notification_task] DB connection reused
2023-05-16 10:04:05,643 [DEBUG] [a51c21e0/send_notification_task] DB connection reused
2023-05-16 10:04:05,645 [DEBUG] [a51c21e0/send_notification_task] DB connection returned to the pool
2023-05-16 10:04:05,649 [INFO] [a51c21e0/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[a51c21e0-afbe-470b-ad37-8cc67c36b47e] succeeded in 0.007250624999869615s: (0, 0)
2023-05-16 10:04:05,650 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffff82d9f7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'f6e85638-de4d-43b3-8dfb-519c77299161', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'f6e85638-de4d-43b3-8dfb-519c77299161', 'shadow': None, 'eta': '2023-05-16T10:04:05.649148+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'parent_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'argsrepr': "('0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', {'address': '0xAbeD9213BDD9228e1845B3a5A23687A17FdF0ff9', 'type': 'INCOMING_ETHER', 'txHash': '0xbb6f8ab2531b3d3de6df08ac2dbe58401f9679b2b87ddb146c3ecb9544e1e472', 'value': '100000000000000', 'chainId': '4201'})", 'kwargsrepr': '{}', 'origin': 'gen1@272bc8c4999e', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-16 10:04:05,650 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffff82d9f7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', 'e4588689-8c4d-40cd-87b1-3568c473b452', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': 'e4588689-8c4d-40cd-87b1-3568c473b452', 'shadow': None, 'eta': '2023-05-16T10:04:05.650001+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'parent_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'type': 'OUTGOING_ETHER', 'txHash': '0xbb6f8ab2531b3d3de6df08ac2dbe58401f9679b2b87ddb146c3ecb9544e1e472', 'value': '100000000000000', 'chainId': '4201'})", 'kwargsrepr': '{}', 'origin': 'gen1@272bc8c4999e', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding': 'utf-8', 'application_headers': {'lang': 'py', 'task':... kwargs:{})
2023-05-16 10:04:05,650 [DEBUG] [bfcd043b/send_notification_task] DB connection returned to the pool
2023-05-16 10:04:05,654 [INFO] [bfcd043b/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[bfcd043b-ce90-42f3-8e88-b3f4a13c9f64] succeeded in 0.013230707998445723s: (0, 0)
2023-05-16 10:04:05,656 [DEBUG] [f6e85638/send_notification_task] DB connection reused
2023-05-16 10:04:05,657 [DEBUG] [e4588689/send_notification_task] DB connection reused
2023-05-16 10:04:05,657 [DEBUG] [e4588689/send_notification_task] DB connection returned to the pool
2023-05-16 10:04:05,662 [INFO] [e4588689/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[e4588689-8c4d-40cd-87b1-3568c473b452] succeeded in 0.005967000004602596s: (0, 0)
2023-05-16 10:04:05,662 [DEBUG] [f6e85638/send_notification_task] DB connection returned to the pool
2023-05-16 10:04:05,665 [INFO] [f6e85638/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[f6e85638-de4d-43b3-8dfb-519c77299161] succeeded in 0.010542709002038464s: (0, 0)
2023-05-16 10:04:05,815 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffff82d9f7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', '36227af9-b0fa-4f3e-8a8f-775543e7249c', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': '36227af9-b0fa-4f3e-8a8f-775543e7249c', 'shadow': None, 'eta': '2023-05-16T10:04:05.814618+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'parent_id': '21453f51-a60a-42a7-9111-ab208c212adf', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'safeTxHash': '0x189f331736e07e280a21b6ff7c1cdb499a5fa0876210131f65368f142e025658', 'type': 'EXECUTED_MULTISIG_TRANSACTION', 'failed': 'false', 'txHash': '0x11c3a66ee654d3938d4c55f6e9e6930c843b446a80f6c2dfcfd63b9a5b378d44', 'chainId': '4201'})", 'kwargsrepr': '{}', 'origin': 'gen1@272bc8c4999e', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding':... kwargs:{})
2023-05-16 10:04:05,816 [DEBUG] [36227af9/send_notification_task] DB connection reused
2023-05-16 10:04:05,816 [DEBUG] [36227af9/send_notification_task] DB connection returned to the pool
2023-05-16 10:04:05,820 [INFO] [36227af9/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[36227af9-b0fa-4f3e-8a8f-775543e7249c] succeeded in 0.00500129099964397s: (0, 0)
2023-05-16 10:04:05,826 [DEBUG] [???/???] TaskPool: Apply <function fast_trace_task at 0xffff82d9f7f0> (args:('safe_transaction_service.notifications.tasks.send_notification_task', '2a34fc30-a62e-45db-9043-1bbceded1c82', {'lang': 'py', 'task': 'safe_transaction_service.notifications.tasks.send_notification_task', 'id': '2a34fc30-a62e-45db-9043-1bbceded1c82', 'shadow': None, 'eta': '2023-05-16T10:04:05.826467+00:00', 'expires': None, 'group': None, 'group_index': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '556151b3-c780-4e19-8a30-ed2f76e8879f', 'parent_id': '21453f51-a60a-42a7-9111-ab208c212adf', 'argsrepr': "('0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', {'address': '0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6', 'safeTxHash': '0x5bc5ab382555a0ddf6f234faed6ee36414eaed84a9bc3f8cb8bc9635e81cff30', 'type': 'EXECUTED_MULTISIG_TRANSACTION', 'failed': 'false', 'txHash': '0xbb6f8ab2531b3d3de6df08ac2dbe58401f9679b2b87ddb146c3ecb9544e1e472', 'chainId': '4201'})", 'kwargsrepr': '{}', 'origin': 'gen1@272bc8c4999e', 'ignore_result': True, 'properties': {'content_type': 'application/json', 'content_encoding':... kwargs:{})
2023-05-16 10:04:05,829 [DEBUG] [2a34fc30/send_notification_task] DB connection reused
2023-05-16 10:04:05,830 [DEBUG] [2a34fc30/send_notification_task] DB connection returned to the pool
2023-05-16 10:04:05,833 [INFO] [2a34fc30/send_notification_task] Task safe_transaction_service.notifications.tasks.send_notification_task[2a34fc30-a62e-45db-9043-1bbceded1c82] succeeded in 0.00587870799790835s: (0, 0)

The chainId is not the expected 4201

However when looking at the logs of the gwc: 

[2023-05-16T10:04:00Z INFO  _] Response succeeded.
[2023-05-16T10:04:14Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages:
[2023-05-16T10:04:14Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6:
[2023-05-16T10:04:14Z INFO  _] Matched: (get_safe_info) GET /v1/chains/<chain_id>/safes/<safe_address>
[2023-05-16T10:04:14Z ERROR _] No matching routes for GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages.
[2023-05-16T10:04:14Z WARN  _] Responding with registered (not_found) 404 catcher.
[2023-05-16T10:04:14Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages::0::404::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages::4201::172.22.0.1
[2023-05-16T10:04:14Z INFO  _] Response succeeded.
[2023-05-16T10:04:14Z INFO  _] Outcome: Success
[2023-05-16T10:04:14Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>::0::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6::4201::172.22.0.1
[2023-05-16T10:04:14Z INFO  _] Response succeeded.
[2023-05-16T10:04:14Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false:
[2023-05-16T10:04:14Z INFO  _] Matched: (get_balances) GET /v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>
[2023-05-16T10:04:14Z INFO  _] Outcome: Success
[2023-05-16T10:04:14Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>::1::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false::4201::172.22.0.1
[2023-05-16T10:04:14Z INFO  _] Response succeeded.
[2023-05-16T10:04:14Z INFO  rocket::server] GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false:
[2023-05-16T10:04:14Z INFO  _] Matched: (get_balances) GET /v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>
[2023-05-16T10:04:14Z INFO  _] Outcome: Success
[2023-05-16T10:04:14Z INFO  safe_client_gateway::monitoring::performance] MT::GET::/v1/chains/<chain_id>/safes/<safe_address>/balances/<fiat>?<trusted>&<exclude_spam>::1::200::/v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/balances/usd?trusted=false::4201::172.22.0.1
[2023-05-16T10:04:14Z INFO  _] Response succeeded.

it is indexing at the API level (I can see the tx when looking at the django admin). However, the front end has no idea it was indexed.

Also, in the logs there is a 404 related to the messages: 

[2023-05-16T10:04:14Z ERROR _] No matching routes for GET /v1/chains/4201/safes/0x1CfD3B2B5BAEA75b222b56439F40E6810F2c2fC6/messages.
[2023-05-16T10:04:14Z WARN  _] Responding with registered (not_found) 404 catcher.

Do you think it could be related?

Uxio0 commented 1 year ago

No, 404 is just that the Safe has no messages or Safe is not indexed. Could you grep send_webhook_task for the notification worker?

The chainId is not the expected 4201

We fixed a bug related to that. Could you go to the admin and remove the Chains table content? image

skimaharvey commented 1 year ago

the send_webhook_task is listed in the initialization section but no task are executing for that message

Uxio0 commented 1 year ago

Delete the chain entity I shared, restart the service and check again

skimaharvey commented 1 year ago

done. Same thing

Uxio0 commented 1 year ago

We just released a hotfix that might affect webhooks, please try: https://github.com/safe-global/safe-transaction-service/releases/tag/v4.19.1

skimaharvey commented 1 year ago

WORKED ! Thank you!

Uxio0 commented 1 year ago

Awesome, good to hear that, I'm closing this.

Thanks for the detailed debugging, you helped us finding issues for networks that we don't have registered

suraneti commented 1 year ago

Just found this issue conversation, I spend two days to find a solution, Jesus.

Uxio0 commented 1 year ago

Sorry about that. @skimaharvey did a great debugging job to let us know what was happening, and it turned to be multiple stacked issues. Everything should be fixed now, we recommend to keep always the service updated