CLN Transactions An error occured: Request failed with status code 500

[openoms]

Logs: $ sudo journalctl -fu blitzapi

Jun 21 07:30:37 z420 python[2324446]: ERROR:uvicorn.error:Exception in ASGI application
Jun 21 07:30:37 z420 python[2324446]: Traceback (most recent call last):
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/protocols/http/h11_impl.py", line 366, in run_asgi
Jun 21 07:30:37 z420 python[2324446]:     result = await app(self.scope, self.receive, self.send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/middleware/proxy_headers.py", line 75, in __call__
Jun 21 07:30:37 z420 python[2324446]:     return await self.app(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await super().__call__(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.middleware_stack(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jun 21 07:30:37 z420 python[2324446]:     raise exc
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, _send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/cors.py", line 84, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jun 21 07:30:37 z420 python[2324446]:     raise exc
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, sender)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jun 21 07:30:37 z420 python[2324446]:     raise e
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await route.handle(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 418, in handle
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await super().__call__(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.middleware_stack(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jun 21 07:30:37 z420 python[2324446]:     raise exc
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, _send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jun 21 07:30:37 z420 python[2324446]:     raise exc
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, sender)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jun 21 07:30:37 z420 python[2324446]:     raise e
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jun 21 07:30:37 z420 python[2324446]:     await route.handle(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 266, in handle
Jun 21 07:30:37 z420 python[2324446]:     await self.app(scope, receive, send)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 65, in app
Jun 21 07:30:37 z420 python[2324446]:     response = await func(request)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 227, in app
Jun 21 07:30:37 z420 python[2324446]:     raw_response = await run_endpoint_function(
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 160, in run_endpoint_function
Jun 21 07:30:37 z420 python[2324446]:     return await dependant.call(**values)
Jun 21 07:30:37 z420 python[2324446]:   File "./app/routers/lightning.py", line 151, in list_all_tx_path
Jun 21 07:30:37 z420 python[2324446]:     return await list_all_tx(successful_only, index_offset, max_tx, reversed)
Jun 21 07:30:37 z420 python[2324446]:   File "./app/repositories/lightning.py", line 72, in list_all_tx
Jun 21 07:30:37 z420 python[2324446]:     return await ln.list_all_tx_impl(successful_only, index_offset, max_tx, reversed)
Jun 21 07:30:37 z420 python[2324446]:   File "./app/repositories/ln_impl/cln_grpc.py", line 218, in list_all_tx_impl
Jun 21 07:30:37 z420 python[2324446]:     pr = await decode_pay_request_impl(pay.bolt11)
Jun 21 07:30:37 z420 python[2324446]:   File "./app/repositories/ln_impl/cln_grpc.py", line 402, in decode_pay_request_impl
Jun 21 07:30:37 z420 python[2324446]:     return PaymentRequest.from_cln_json(json.loads(decoded))
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/lib/python3.9/json/__init__.py", line 346, in loads
Jun 21 07:30:37 z420 python[2324446]:     return _default_decoder.decode(s)
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/lib/python3.9/json/decoder.py", line 337, in decode
Jun 21 07:30:37 z420 python[2324446]:     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
Jun 21 07:30:37 z420 python[2324446]:   File "/usr/lib/python3.9/json/decoder.py", line 355, in raw_decode
Jun 21 07:30:37 z420 python[2324446]:     raise JSONDecodeError("Expecting value", s, err.value) from None
Jun 21 07:30:37 z420 python[2324446]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

[openoms]

updating the cln-grpc now

• same error with the latest cln-grpc from CLN master

updating to CLN v0.11.2.rc1 now

[openoms]

The above is on a Debian11 amd64 server with a possibly dirty state.

My RPi4 test node has no error, but no transaction history either.

Is anyone testing with and active CLN node on an RPi? @cstenglein maybe?

[fusion44]

Hmm looks like some unexpected data is coming from CLN and the API tries to decode it. I have no immediate solution other than spreading print statements all around the code.

[openoms]

Migrated the the CLN node to the fresh v1.8.0rc2 RPi4. Good news that the migration works well, but the error is the same.

Would it be useful to share the cli listtranctions / listpays output with you? It has some force closes and BOLT12 things which might be unaccounted for in the parsing.

[openoms]

Trying to pay an invoice: The Send button only spinning and in the logs:

Jun 22 15:49:36 raspberrypi python[2912]: ERROR:uvicorn.error:Exception in ASGI application
Jun 22 15:49:36 raspberrypi python[2912]: Traceback (most recent call last):
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/protocols/http/h11_impl.py", line 366, in run_asgi
Jun 22 15:49:36 raspberrypi python[2912]:     result = await app(self.scope, self.receive, self.send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/middleware/proxy_headers.py", line 75, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     return await self.app(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await super().__call__(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.middleware_stack(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     raise exc
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, _send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/cors.py", line 84, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     raise exc
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, sender)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     raise e
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await route.handle(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 418, in handle
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await super().__call__(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.middleware_stack(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     raise exc
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, _send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     raise exc
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, sender)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     raise e
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jun 22 15:49:36 raspberrypi python[2912]:     await route.handle(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 266, in handle
Jun 22 15:49:36 raspberrypi python[2912]:     await self.app(scope, receive, send)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 65, in app
Jun 22 15:49:36 raspberrypi python[2912]:     response = await func(request)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 227, in app
Jun 22 15:49:36 raspberrypi python[2912]:     raw_response = await run_endpoint_function(
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 160, in run_endpoint_function
Jun 22 15:49:36 raspberrypi python[2912]:     return await dependant.call(**values)
Jun 22 15:49:36 raspberrypi python[2912]:   File "./app/routers/lightning.py", line 151, in list_all_tx_path
Jun 22 15:49:36 raspberrypi python[2912]:     return await list_all_tx(successful_only, index_offset, max_tx, reversed)
Jun 22 15:49:36 raspberrypi python[2912]:   File "./app/repositories/lightning.py", line 72, in list_all_tx
Jun 22 15:49:36 raspberrypi python[2912]:     return await ln.list_all_tx_impl(successful_only, index_offset, max_tx, reversed)
Jun 22 15:49:36 raspberrypi python[2912]:   File "./app/repositories/ln_impl/cln_grpc.py", line 218, in list_all_tx_impl
Jun 22 15:49:36 raspberrypi python[2912]:     pr = await decode_pay_request_impl(pay.bolt11)
Jun 22 15:49:36 raspberrypi python[2912]:   File "./app/repositories/ln_impl/cln_grpc.py", line 402, in decode_pay_request_impl
Jun 22 15:49:36 raspberrypi python[2912]:     return PaymentRequest.from_cln_json(json.loads(decoded))
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/lib/python3.9/json/__init__.py", line 346, in loads
Jun 22 15:49:36 raspberrypi python[2912]:     return _default_decoder.decode(s)
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/lib/python3.9/json/decoder.py", line 337, in decode
Jun 22 15:49:36 raspberrypi python[2912]:     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
Jun 22 15:49:36 raspberrypi python[2912]:   File "/usr/lib/python3.9/json/decoder.py", line 355, in raw_decode
Jun 22 15:49:36 raspberrypi python[2912]:     raise JSONDecodeError("Expecting value", s, err.value) from None
Jun 22 15:49:36 raspberrypi python[2912]: json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

[openoms]

Cannot generate an invoice in the webUI, but if I do in the CLI it appears in the webUI on a fresh node:

[openoms]

update: managed to reproduce the problem on my node above with a single private channel after I sent and received a keysend payment.

Now shows the same error as in the OP.

Then proceeded to delete the sent payment with cl delpay payment_hash complete and the error is gone and reappeared when sending another keysend.

Receiving keysend appears ok.

Example listpays entry for keysend sent:

{
   "pays": [
      {
         "destination": "xxxxxxxxx",
         "payment_hash": "ab42039c444527aa0082b1c5ed50f2095a6c58fa83dd01c074831d3e4ee51111",
         "status": "complete",
         "created_at": 1656184473,
         "preimage": "e9a94c747c611041010ce68b4d1fad4d7cc13dbe5b0a8ac3dd6b26643024007a",
         "amount_msat": "1000msat",
         "amount_sent_msat": "1000msat"
      }
   ]
}

vs bolt11:

      {
         "bolt11": "lnbcxxxx",
         "destination": "xxxxx",
         "payment_hash": "9180b99266cc60fe6f1f2d65e9014099983fea8821c2acaf09571e4c8d7052f4",
         "status": "complete",
         "created_at": 1655298043,
         "preimage": "4b0ff72e92f49599a18dc5cc24f367e60ec20aa526ea225fd369e88f2d9d9254",
         "amount_msat": "50000000msat",
         "amount_sent_msat": "50014092msat",
         "number_of_parts": 5
      },

and bolt12:

      {
         "bolt12": "lnixxxx",
         "destination": "xxxxxx",
         "payment_hash": "20d62bb5ee14e6ddef22eebbaec767949cd01971ef0bfe8e56f2c9ee3649be0e",
         "status": "complete",
         "created_at": 1632617923,
         "preimage": "d367f7ab93f57f83cd89503686138b6e96e8e8ccd699d5724213e5bfb9d3b9a0",
         "amount_msat": "21000msat",
         "amount_sent_msat": "21007msat"
      },

It is failing with all sent payments, not just keysend.

[openoms]

Not sure how to proceed here. Should we try to rebuild the proto files? (running the CLN v0.11.2rc3 now)

[fusion44]

Yes, seems like there have been changes to the proto file since last release. I'll update early next week or maybe even this evening.

[openoms]

Discussed briefly on the Core Lightning dev meeting:

• the protofiles should be fine within v0.11.x as there are no API changes
• will likely need update between major versions (v0.12) -using an older CLN with a newer protofile will ikely break

[fusion44]

@openoms Please test latest main branch. I could not reproduce the exact error as in OP. I've fixed the errors I got after creating a few keysend payments.

[openoms]

After I restart the blitzapi on latest starting to get an error about hop_hints. I have a private channel between my two test nodes so the invoices contain a hop hint.

Jul 04 13:53:20 raspberrypi python[2500196]: ERROR:uvicorn.error:Exception in ASGI application
Jul 04 13:53:20 raspberrypi python[2500196]: Traceback (most recent call last):
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/protocols/http/h11_impl.py", line 366, in run_asgi
Jul 04 13:53:20 raspberrypi python[2500196]:     result = await app(self.scope, self.receive, self.send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/middleware/proxy_headers.py", line 75, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     return await self.app(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await super().__call__(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.middleware_stack(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     raise exc
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, _send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/cors.py", line 84, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     raise exc
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, sender)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     raise e
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await route.handle(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 418, in handle
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await super().__call__(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.middleware_stack(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     raise exc
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, _send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     raise exc
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, sender)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     raise e
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jul 04 13:53:20 raspberrypi python[2500196]:     await route.handle(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 266, in handle
Jul 04 13:53:20 raspberrypi python[2500196]:     await self.app(scope, receive, send)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 65, in app
Jul 04 13:53:20 raspberrypi python[2500196]:     response = await func(request)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 227, in app
Jul 04 13:53:20 raspberrypi python[2500196]:     raw_response = await run_endpoint_function(
Jul 04 13:53:20 raspberrypi python[2500196]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 160, in run_endpoint_function
Jul 04 13:53:20 raspberrypi python[2500196]:     return await dependant.call(**values)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/routers/lightning.py", line 151, in list_all_tx_path
Jul 04 13:53:20 raspberrypi python[2500196]:     return await list_all_tx(successful_only, index_offset, max_tx, reversed)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/repositories/lightning.py", line 72, in list_all_tx
Jul 04 13:53:20 raspberrypi python[2500196]:     return await ln.list_all_tx_impl(successful_only, index_offset, max_tx, reversed)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/repositories/ln_impl/cln_grpc.py", line 229, in list_all_tx_impl
Jul 04 13:53:20 raspberrypi python[2500196]:     pr = await decode_pay_request_impl(pay.bolt11)
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/repositories/ln_impl/cln_grpc.py", line 428, in decode_pay_request_impl
Jul 04 13:53:20 raspberrypi python[2500196]:     return PaymentRequest.from_cln_json(json.loads(decoded))
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/models/lightning.py", line 1503, in from_cln_json
Jul 04 13:53:20 raspberrypi python[2500196]:     routes = [RouteHint.from_cln_json(rh) for rh in r["routes"]]
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/models/lightning.py", line 1503, in <listcomp>
Jul 04 13:53:20 raspberrypi python[2500196]:     routes = [RouteHint.from_cln_json(rh) for rh in r["routes"]]
Jul 04 13:53:20 raspberrypi python[2500196]:   File "./app/models/lightning.py", line 386, in from_cln_json
Jul 04 13:53:20 raspberrypi python[2500196]:     hop_hints = [HopHint.from_cln_json(hh) for hh in h.hop_hints]
Jul 04 13:53:20 raspberrypi python[2500196]: AttributeError: 'list' object has no attribute 'hop_hints'

[fusion44]

Oh dang, yes that may very well be. Will fix it.

[openoms]

Still have the original error in the webUI, but new in the logs:

Jul 05 07:43:37 raspberrypi python[2450317]: ERROR:uvicorn.error:Exception in ASGI application
Jul 05 07:43:37 raspberrypi python[2450317]: Traceback (most recent call last):
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/protocols/http/h11_impl.py", line 366, in run_asgi
Jul 05 07:43:37 raspberrypi python[2450317]:     result = await app(self.scope, self.receive, self.send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/uvicorn/middleware/proxy_headers.py", line 75, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     return await self.app(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await super().__call__(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.middleware_stack(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     raise exc
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, _send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/cors.py", line 84, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     raise exc
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, sender)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     raise e
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await route.handle(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 418, in handle
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/applications.py", line 269, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await super().__call__(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/applications.py", line 124, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.middleware_stack(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 184, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     raise exc
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/middleware/errors.py", line 162, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, _send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 93, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     raise exc
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/exceptions.py", line 82, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, sender)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 21, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     raise e
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/middleware/asyncexitstack.py", line 18, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 670, in __call__
Jul 05 07:43:37 raspberrypi python[2450317]:     await route.handle(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 266, in handle
Jul 05 07:43:37 raspberrypi python[2450317]:     await self.app(scope, receive, send)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/starlette/routing.py", line 65, in app
Jul 05 07:43:37 raspberrypi python[2450317]:     response = await func(request)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 227, in app
Jul 05 07:43:37 raspberrypi python[2450317]:     raw_response = await run_endpoint_function(
Jul 05 07:43:37 raspberrypi python[2450317]:   File "/usr/local/lib/python3.9/dist-packages/fastapi/routing.py", line 160, in run_endpoint_function
Jul 05 07:43:37 raspberrypi python[2450317]:     return await dependant.call(**values)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "./app/routers/lightning.py", line 151, in list_all_tx_path
Jul 05 07:43:37 raspberrypi python[2450317]:     return await list_all_tx(successful_only, index_offset, max_tx, reversed)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "./app/repositories/lightning.py", line 72, in list_all_tx
Jul 05 07:43:37 raspberrypi python[2450317]:     return await ln.list_all_tx_impl(successful_only, index_offset, max_tx, reversed)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "./app/repositories/ln_impl/cln_grpc.py", line 229, in list_all_tx_impl
Jul 05 07:43:37 raspberrypi python[2450317]:     pr = await decode_pay_request_impl(pay.bolt11)
Jul 05 07:43:37 raspberrypi python[2450317]:   File "./app/repositories/ln_impl/cln_grpc.py", line 428, in decode_pay_request_impl
Jul 05 07:43:37 raspberrypi python[2450317]:     return PaymentRequest.from_cln_json(json.loads(decoded))
Jul 05 07:43:37 raspberrypi python[2450317]:   File "./app/models/lightning.py", line 1523, in from_cln_json
Jul 05 07:43:37 raspberrypi python[2450317]:     description=r["description"],
Jul 05 07:43:37 raspberrypi python[2450317]: KeyError: 'description'

[openoms]

There is change. I get now:

Transactions

An error occured: Received message larger than max (4657891 vs. 4194304)

Logs:

$ sudo journalctl -fu blitzapi
Aug 26 09:46:56 raspberrypi sudo[1163018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 26 09:46:56 raspberrypi sudo[1163018]: pam_unix(sudo:session): session closed for user root
Aug 26 09:46:56 raspberrypi sudo[1162722]: pam_unix(sudo:session): session closed for user root
Aug 26 09:46:56 raspberrypi python[2819820]: E0826 09:46:56.357215458 2819820 fork_posix.cc:76]           Other threads are currently calling into gRPC, skipping fork() handlers
Aug 26 09:46:56 raspberrypi sudo[1163030]: blitzapi : PWD=/home/blitzapi/blitz_api ; USER=root ; COMMAND=/usr/bin/bash /home/admin/config.scripts/bonus.btc-rpc-explorer.sh status
Aug 26 09:46:56 raspberrypi sudo[1163030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1006)
Aug 26 09:46:56 raspberrypi sudo[1163030]: pam_unix(sudo:session): session closed for user root
Aug 26 09:47:15 raspberrypi python[2819820]: INFO:     127.0.0.1:57950 - "GET /lightning/list-all-tx?reversed=true HTTP/1.0" 500 Internal Server Error

[fusion44]

OK I've seen that one. It seems this is a gRPC problem for nodes with a lot of transactions.

[cstenglein]

@fusion44 any update on the Received message larger than max issue? On the RaspiBlitz TG channel someone still had the issue in 1.9.0rc1

[fusion44]

@openoms do still receive this error? If so, does the size of the numbers in the error change?

Can you open the file cln_grpc.py: https://github.com/fusion44/blitz_api/blob/bb0dcd69d2e84c76477244f5e0cd0c158e9b9801/app/lightning/impl/cln_grpc.py#L131 and change the line 131

        opts = (("grpc.ssl_target_name_override", "cln"),)

to

        opts = (
            ("grpc.ssl_target_name_override", "cln"),
            ("grpc.max_receive_message_length", 1024 * 1024 * 10),
        )

and then restart the server and see if the error goes away. This will set the max receive message size to 10 MB instead of the default 4 MB. If this works I'll make this configurable via the .env file. During my research I found that the library used by CLN doesn't have a cap by default. For LND I'm not sure, couldn't find any reliable limit. Most clients have a limit of 4 MB by default.

[openoms]

Made the change and now getting a timeout with cln-grpc running hot, but nothing in the blitzapi logs.

[fusion44]

Please try setting log_level=INFO to log_level=DEBUG in the .env file. This should give you more information about what went wrong. Although the logging system remains a mess because I am silently eating some error messages somewhere. I am currently working on fixing this.

For the next major release I will add a json-rpc implementation. I'm really bothered by the high CPU usage. Also, gRPC doesn't really fit well with the dynamic plugin-based architecture or CLN.

[openoms]

Added the log_level=DEBUG line to /home/blitztapi/blitz_api/.env (presumed that's the right place despite there was no log_level= entry before) but only getting:

Mar 18 14:02:44 raspberrypi systemd[1]: Started blitzapi needs the wg service before it can start successfully.
Mar 18 14:02:58 raspberrypi python[1062846]: 2023-03-18 14:02:58 | ℹ️ | logging.py:87 | Started server process [1062846]                        
Mar 18 14:02:58 raspberrypi python[1062846]: 2023-03-18 14:02:58 | ℹ️ | logging.py:87 | Waiting for application startup.
Mar 18 14:02:58 raspberrypi python[1062846]: 2023-03-18 14:02:58 | ℹ️ | logging.py:87 | Application startup complete.
Mar 18 14:02:58 raspberrypi python[1062846]: 2023-03-18 14:02:58 | ℹ️ | logging.py:87 | Uvicorn running on http://0.0.0.0:11111 (Press CTRL+C to quit)
Mar 18 14:02:58 raspberrypi python[1062846]: 2023-03-18 14:02:58 | ℹ️ | cln_grpc.py:103 | CLN_GRPC: Establishing a connection to the CLN daemon ...            Mar 18 14:03:07 raspberrypi python[1062846]: ./app/api/utils.py:206: UserWarning: call_script is deprecated. Use call_script2 instead.
Mar 18 14:03:07 raspberrypi python[1062846]:   warnings.warn("call_script is deprecated. Use call_script2 instead.")                                          
Mar 18 14:03:08 raspberrypi python[1062846]: 2023-03-18 14:03:08 | ℹ️ | logging.py:87 | 127.0.0.1:46180 - "POST /system/login HTTP/1.0" 200
Mar 18 14:03:09 raspberrypi python[1062846]: 2023-03-18 14:03:09 | ℹ️ | logging.py:87 | 127.0.0.1:46352 - "GET /sse/subscribe HTTP/1.0" 200
Mar 18 14:03:09 raspberrypi python[1062846]: 2023-03-18 14:03:09 | ℹ️ | logging.py:87 | 127.0.0.1:46354 - "GET /lightning/list-all-tx?reversed=true HTTP/1.0" 500                                                                             
Mar 18 14:03:09 raspberrypi python[1062846]: 2023-03-18 14:03:09 | ❌ | logging.py:87 | Exception in ASGI application

[fusion44]

I'll close this for now. I hope the max receive message size increases fixed this. If not, please open a new issue.