Snap-store-proxy air-gapped install issues

mathervenrate · April 13, 2023, 2:47pm

Hello,

sorry in advance if its not the correct category, but since other snap-store-proxy topics are not limited to one category, I wasn’t sure where to place it.

To the Issue:

The Troubleshoot Page in the Snap-Store-Proxy Documentation is limited, and does not contain my issue. Also: Report a Bug links to a launchpad bug website, but the in “overview” linked URL to the Snap-Store-Proxy bug page on launchpad is not existing.

I have followed the whole Process. sudo snap-store-proxy status returns the following.

Store URL: https://snap.store
Store DB: ok
Failed to fetch local assertions: 503 Server Error: Service Unavailable for url: http://127.0.0.1:5000/v1/assertions/account-key
Store is in device authenticated air-gapped mode
Store ID: ThHsUgkrNKk39yIOxr0Prf2903Kh691e
Custom local stores: none
Local account keys:
  Account ID    Name    Public Key SHA3-384
Internal Service Status:
  memcached: running
  nginx: running
  packagereview: not running: 500 Server Error: INTERNAL SERVER ERROR for url: http://127.0.0.1:8006/_status/check?review-tools
  packagereview-worker: not running: Command '['/snap/snap-store-proxy/94/bin/packagereview-worker-wrapper', 'ping', 'amqp://']' returned non-zero exit status 1.
  publishergw: running
  rabbitmq-server: not running: [Errno 111] Connection refused
  snapassert: running
  snapauth: running
  snapdevicegw: running
  snapdevicegw-local: running
  snapident: running
  snapproxy: running
  snaprevs: running
  snapstorage: not running: [Errno 111] Connection refused

My Testenvironment in a VM did not throw any of such errors. Docu does not help in any way, and i have no idea how to debug.

Also theres no Documentation about “snapstorage” anywhere. I thought about to externalize the snapstorage to NFS Share or S3, but did not find a way to configure it.

Maybe someone has an idea.

Also, I have no idea if a License for the Air-Gapped snap-store-proxy is needed or not. Docu has no info about it.

Thanks,

Marcel

mathervenrate · April 14, 2023, 1:30pm

I made an advancement.

It seems that the connected DB may have some kind of conneciton issues, even though the DB is fully accessable. (???, i dont understand it. )

Second issue:

RabbitMQ Service is unable to start due to epmd not beeing started by the snap-store-proxy.

I have no idea, why it is not being started, but my test environments do start this process fine. The Installation which throws above errors, does not start the epmd process, which is necessary to start the RabbitMQ Service.

If it is started manually it works fine, but i dont want to start it manually. It should be started by a Process or Service, I just cannot figure out which one starts it.

Wouldve loved someone from the snap-store-proxy team to give some details. But thats probably hopeless.

Thanks,

Marcel.

suligap · April 14, 2023, 2:47pm

Hi. Bugs can be reported at https://bugs.launchpad.net/snapstore-server.

The troubleshooting page mentions the snap logs snap-store-proxy command. The output of that would be very helpful in trying to debug your issue.

sudo snap restart snap-store-proxy can be used to restart all services and sudo snap restart snap-store-proxy.<service-name> restarts a specific service.

As per https://docs.ubuntu.com/snap-store-proxy/en/register:

For evaluation purposes, we automatically grant the use of up to 25 devices.

There is no support for external/object storage currently.

mathervenrate · April 17, 2023, 7:19am

Thanks for the reply.

Also, thanks to the hint about the snap logs command. Heres the output.

~$ sudo snap logs snap-store-proxy
2023-04-17T07:56:02+02:00 snap-store-proxy.publishergw[27088]: 2023-04-17 05:56:02.533Z INFO talisker.wsgi "GET /_status/check" method=GET path=/_status/check status=200 view=publishergw.webapp.health_check duration_ms=1.947 ip=127.0.0.1 proto=HTTP/1.1 length=12 ua=python-requests/2.27.1 request_id=8f8697ab-fa19-4759-ad8c-ee4b8d68ea4d
2023-04-17T07:56:02+02:00 snap-store-proxy.publishergw[27088]: 127.0.0.1 - - [17/Apr/2023:07:56:02 +0200] "GET /_status/check HTTP/1.1" 200 12 "-" "python-requests/2.27.1"
2023-04-17T07:56:02+02:00 snap-store-proxy.snapstorage[26853]: 2023-04-17 07:56:02.545Z INFO snapstorage "GET /_status/check" duration_ms=5.949246 ip="127.0.0.1" length=18 method="GET" path="/_status/check" proto="HTTP/1.1" request_id="f0904813-4dc9-495e-845b-9d1f463cdee5" status=200 ua="python-requests/2.27.1" url="127.0.0.1:8011/_status/check"
2023-04-17T07:56:02+02:00 snap-store-proxy.snapident[26903]: 2023-04-17 05:56:02.567Z INFO talisker.wsgi "GET /_status/check" method=GET path=/_status/check status=200 view=snapident.webapp.health_check duration_ms=18.795 ip=127.0.0.1 proto=HTTP/1.1 length=12 ua=python-requests/2.27.1 sql_count=7 sql_time_ms=0.869 request_id=6a1632ce-b535-4250-88c5-f8c62c18e8cc
2023-04-17T07:56:02+02:00 snap-store-proxy.snapident[26903]: 127.0.0.1 - - [17/Apr/2023:07:56:02 +0200] "GET /_status/check HTTP/1.1" 200 12 "-" "python-requests/2.27.1"
2023-04-17T07:56:11+02:00 snap-store-proxy.packagereview-worker[26954]: 2023-04-17 05:56:11.004Z ERROR celery.worker.consumer.consumer "consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.\nTrying again in 12.00 seconds... (6/100)\n"
2023-04-17T07:56:23+02:00 snap-store-proxy.packagereview-worker[26954]: 2023-04-17 05:56:23.017Z ERROR celery.worker.consumer.consumer "consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.\nTrying again in 14.00 seconds... (7/100)\n"
2023-04-17T07:56:37+02:00 snap-store-proxy.packagereview-worker[26954]: 2023-04-17 05:56:37.034Z ERROR celery.worker.consumer.consumer "consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.\nTrying again in 16.00 seconds... (8/100)\n"
2023-04-17T07:56:53+02:00 snap-store-proxy.packagereview-worker[26954]: 2023-04-17 05:56:53.052Z ERROR celery.worker.consumer.consumer "consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.\nTrying again in 18.00 seconds... (9/100)\n"
2023-04-17T07:57:11+02:00 snap-store-proxy.packagereview-worker[26954]: 2023-04-17 05:57:11.073Z ERROR celery.worker.consumer.consumer "consumer: Cannot connect to amqp://guest:**@127.0.0.1:5672//: [Errno 111] Connection refused.\nTrying again in 20.00 seconds... (10/100)\n"

The 10 latest entries are definitely not enough for an accumulation of service logs. - Pasting the whole log is definitely too much. As described in my second answer, I already did some digging, and figured out that the epmd --daemon is not started by the snap-store-proxy, and it is not running locally either. The necessary port (4369) is also not blocked by any process, according to ss.

I used systemctl and journalctl to view the corresponding service logs. From there I saw the following issue on the snap-store-proxy.rabitmq-server service.

2023-04-17T07:55:30+02:00 epmd[26289]: epmd: failed to bind socket
2023-04-17T07:55:30+02:00 snap-store-proxy.rabbitmq-server[26282]: Protocol 'inet_tcp': register/listen error: econnrefused
2023-04-17T07:55:30+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Main process exited, code=exited, status=1/FAILURE
2023-04-17T07:55:30+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Failed with result 'exit-code'.
2023-04-17T07:55:31+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Scheduled restart job, restart counter is at 3.
2023-04-17T07:55:31+02:00 systemd[1]: Stopped Service for snap application snap-store-proxy.rabbitmq-server.
2023-04-17T07:55:31+02:00 systemd[1]: Started Service for snap application snap-store-proxy.rabbitmq-server.
2023-04-17T07:55:31+02:00 snap-store-proxy.rabbitmq-server[26435]: Protocol 'inet_tcp': register/listen error: econnrefused
2023-04-17T07:55:31+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Main process exited, code=exited, status=1/FAILURE
2023-04-17T07:55:31+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Failed with result 'exit-code'.
2023-04-17T07:55:33+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Scheduled restart job, restart counter is at 4.
2023-04-17T07:55:33+02:00 systemd[1]: Stopped Service for snap application snap-store-proxy.rabbitmq-server.
2023-04-17T07:55:33+02:00 systemd[1]: Started Service for snap application snap-store-proxy.rabbitmq-server.
2023-04-17T07:55:33+02:00 snap-store-proxy.rabbitmq-server[26588]: Protocol 'inet_tcp': register/listen error: econnrefused
2023-04-17T07:55:33+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Main process exited, code=exited, status=1/FAILURE
2023-04-17T07:55:33+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Failed with result 'exit-code'.
2023-04-17T07:55:34+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Scheduled restart job, restart counter is at 5.
2023-04-17T07:55:34+02:00 systemd[1]: Stopped Service for snap application snap-store-proxy.rabbitmq-server.
2023-04-17T07:55:34+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Start request repeated too quickly.
2023-04-17T07:55:34+02:00 systemd[1]: snap.snap-store-proxy.rabbitmq-server.service: Failed with result 'exit-code'.
2023-04-17T07:55:34+02:00 systemd[1]: Failed to start Service for snap application snap-store-proxy.rabbitmq-server.

I think it is unable to bind socket, because the corresponding process is not running.

~$ ls -la /snap/snap-store-proxy/94/usr/lib/erlang/erts-10.6.4/bin/epmd
-rwxr-xr-x 1 root root 63896 Feb 18  2020 /snap/snap-store-proxy/94/usr/lib/erlang/erts-10.6.4/bin/epmd*

$ ps aux | grep epmd
user      28176  0.0  0.0   6300   720 pts/0    S+   08:25   0:00 grep --color=auto epmd

On another test machine, this exact process is starting without issues and is running. So its either

not started at all, or
started but crashes, but doesnt produce logs in the service logs.

Running this process manually as

sudo /snap/snap-store-proxy/94/usr/lib/erlang/erts-10.6.4/bin/epmd -daemon and
restarting rabbitmq-server sudo snap restart snap-store-proxy.rabbitmq-server results in an fully running snap-store, but it should be figured out why this happens.

Since it works, i’ll continue evaluating at this point, to finish my project.

Thanks,

Marcel