Failure on arm32 machine #79

woncheol-kim · 2021-06-26T11:30:10Z

Hi, I've been using the old qmcgaw/cloudflare-dns-server and today I've found that the new qmcgaw/dns is available. The new docker image works fine on most of my systems except one:

It's Synology DS416j NAS which does not officially support docker, with Marvell Armada (armhf) CPU. But docker for arm32v7 works anyway with limited functionality, and the old qmcgaw/cloudflare-dns-server works fine with two obligatory options:
--network=host
--user=root

The problem is that the new qmcgaw/dns ends up with failure with messages as below:

2021/06/26 11:00:34 INFO Unbound version: 1.13.0
2021/06/26 11:00:34 INFO Settings summary:
 |--Unbound settings:
    |--DNS over TLS providers:
        |--Cloudflare
    |--Listening port: 53
    |--Access control:
        |--Allowed:
            |--0.0.0.0/0
            |--::/0
    |--Caching: enabled
    |--IPv4 resolution: enabled
    |--IPv6 resolution: disabled
    |--Verbosity level: 1/5
    |--Verbosity details level: 0/4
    |--Validation log level: 0/2
    |--Username: 
 |--Blacklisting settings:
    |--Blocked categories: malicious, surveillance, ads
    |--Hostnames unblocked: 1
    |--Additional IP networks blocked: 13
 |--Check DNS: enabled
 |--Update: every 24h0m0s
2021/06/26 11:00:34 INFO using DNS address 127.0.0.1 internally
2021/06/26 11:00:34 INFO generating Unbound configuration
2021/06/26 11:00:34 INFO starting unbound
2021/06/26 11:00:34 INFO healthcheck server: listening on 127.0.0.1:9999
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] warning: setrlimit: Operation not permitted
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] warning: cannot increase max open fds from 1024 to 8266
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] warning: continuing with less udp ports: 477
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] warning: increase ulimit or decrease threads, ports in config to remove this warning
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] notice: init module 0: validator
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] notice: init module 1: iterator
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:0] info: start of service (unbound 1.13.0).
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: ssl handshake failed crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] notice: ssl handshake failed 1.0.0.1 port 853
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: ssl handshake failed crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time
2021/06/26 11:00:34 INFO [8573204612050321408] unbound[13:1] error: and additionally crypto error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed
2021/06/26 11:00:34 WARN Caught OS signal, shutting down
2021/06/26 11:00:34 WARN healthcheck server: shutting down (context canceled)
2021/06/26 11:00:34 WARN healthcheck server: shut down
2021/06/26 11:00:39 WARN Shutdown timed out

In fact, the ssl handshake failure is repeated endlessly and the last part of the messages are the result of my interruption with ctrl+c.

The text was updated successfully, but these errors were encountered:

qdm12 · 2021-06-26T13:18:26Z

See https://github.com/qdm12/gluetun/wiki/32-bit-setup

Alternatively use qmcgaw/dns:v2.0.0-beta

I'll close the issue once I add documentation for it, thanks!

woncheol-kim · 2021-06-26T20:13:29Z

I've tried qmcgaw/dns:v2.0.0-beta and it ended up with error:

docker: Error response from daemon: linux spec user: unable to find user root: no matching entries in passwd file.

qdm12 · 2021-06-27T04:09:53Z

Ah maybe remove the --user flag you pass to your Docker command? The container runs on Scratch (no OS) with v2 so there is no user names. Alternatively you can use user ids. Note that you shouldn't run containers as root, ideally leave it to the default user ID 1000 (so don't specify any user).

woncheol-kim · 2021-06-27T04:22:51Z

I had already tried that and the error messages look like this:

2021/06/27 04:19:08 INFO using DNS address 127.0.0.1 internally
2021/06/27 04:19:08 INFO healthcheck server: listening on 127.0.0.1:9999
2021/06/27 04:19:08 INFO starting DNS server
2021/06/27 04:19:08 INFO DNS server listening on :53
2021/06/27 04:19:14 INFO unbound loop exited
2021/06/27 04:19:14 WARN healthcheck server: shutting down (context canceled)
2021/06/27 04:19:14 ERROR DNS server shutdown error: dns: server not started
2021/06/27 04:19:14 ERROR DNS is not working after 10 tries: lookup github.com on 1.1.1.1:53: read udp 127.0.0.1:53983->127.0.0.1:53: read: connection refused
2021/06/27 04:19:14 INFO Shutdown successful

Maybe it's time to abandon my old NAS... (frustrated)

qdm12 · 2021-06-27T04:27:54Z

Please don't 😉 You're helping me fix my program for your architecture, it's pretty useful, if that can motivate you!

Now these logs are from the latest or v1.x.x image, are you sure you are running that qmcgaw/dns:v2.0.0-beta image?

If you can please create another issue if the openssl error (due to the 32 bit) is fixed now, that would be great, thanks!

edit: also going to bed will take a look tomorrow!

woncheol-kim · 2021-06-27T04:36:36Z

Thanks that you're willing to help me. :)
I don't understand your point when you mentioned openssl, but the entire messages with my docker command is as below:

docker run --rm --network=host --name cloudflare0 qmcgaw/dns:v2.0.0-beta

=========================================
========= DNS over TLS container ========
=========================================
=========================================
=== Made with ❤️  by github.com/qdm12 ====
=========================================

Running version v2.0.0-beta built on 2021-05-15T17:25:05Z (commit 83c928e)


🔧  Need help? https://github.com/qdm12/dns/issues/new
💻  Email? quentin.mcgaw@gmail.com
☕  Slack? Join from the Slack button on Github
💸  Help me? https://github.com/sponsors/qdm12
2021/06/27 04:32:02 WARN Environment variable "IPV6" is deprecated, use the following instead: DOT_CONNECT_IPV6
2021/06/27 04:32:02 WARN Environment variable "IPV4" is deprecated, use the following instead: DOT_CONNECT_IPV6
2021/06/27 04:32:02 INFO Settings summary:
 |--Upstream type: DoT
 |--DoT settings:
    |--Resolver:
       |--DNS over TLS providers:
          |--Cloudflare
          |--Google
       |--Fallback plaintext DNS providers:
          |--Cloudflare
       |--Query timeout: 3s
       |--Connecting over: IPv4
    |--Listening port: 53
    |--Caching:
       |--Type: lru
       |--Max entries: 10000
    |--Blacklist:
       |--Blacklisting is disabled
 |--Blacklist settings:
    |--Blocked categories: malicious
    |--Additional IP networks blocked: 13
 |--Check DNS: enabled
 |--Update: every 24h0m0s
 |--Log level: INFO
 |--Query log settings:
    |--Status: disabled
2021/06/27 04:32:02 INFO healthcheck server: listening on 127.0.0.1:9999
2021/06/27 04:32:02 INFO using DNS address 127.0.0.1 internally
2021/06/27 04:32:02 INFO starting DNS server
2021/06/27 04:32:02 INFO DNS server listening on :53
2021/06/27 04:32:07 INFO unbound loop exited
2021/06/27 04:32:07 WARN healthcheck server: shutting down (context canceled)
2021/06/27 04:32:07 ERROR DNS server shutdown error: dns: server not started
2021/06/27 04:32:07 ERROR DNS is not working after 10 tries: lookup github.com on 1.1.1.1:53: read udp 127.0.0.1:50010->127.0.0.1:53: read: connection refused
2021/06/27 04:32:07 INFO Shutdown successful

qdm12 · 2021-06-27T14:41:32Z

Now these logs are from the latest or v1.x.x image, are you sure you are running that qmcgaw/dns:v2.0.0-beta image?

I changed in 904c5d0 the unbound loop name to run loop since there is no more unbound, that's why it confused me on my phone thinking you were still running v1.x.x sorry!

I don't understand your point when you mentioned openssl

unbound[13:1] error: and additionally crypto error:0D0D90AD:asn1 encoding routines:ASN1_TIME_adj:error getting time to fix this use what's documented here; But also I recommended the alternative to use :v2.0.0-beta so never mind, my bad! 😄

with my docker command

I think --network=host is at fault. You should really not run this as host, there is not much point to do it anyway 😉 First try with:

docker run -it --rm --name cloudflare0 -p 53:53/udp qmcgaw/dns:v2.0.0-beta

And see if it crashes as well?

and the error messages look like this

Also for your own information, the log lines order is not intuitive, since everything in the code is quite asynchronous/parallel. From cause to effect it is actually:

2021/06/27 04:32:07 ERROR DNS is not working after 10 tries: lookup github.com on 1.1.1.1:53: read udp 127.0.0.1:50010->127.0.0.1:53: read: connection refused
2021/06/27 04:32:07 ERROR DNS server shutdown error: dns: server not started
2021/06/27 04:32:07 INFO unbound loop exited
2021/06/27 04:32:07 WARN healthcheck server: shutting down (context canceled)
2021/06/27 04:32:07 INFO Shutdown successful

So really the DNS server gets shutdown because the try to resolve github.com did not work out. For some reason it seems the DNS did not manage to start, not sure why though.

woncheol-kim · 2021-06-27T21:21:02Z

I think --network=host is at fault. You should really not run this as host, there is not much point to do it anyway 😉 First try with:
docker run -it --rm --name cloudflare0 -p 53:53/udp qmcgaw/dns:v2.0.0-beta

Bridge network does not work on my old system. Interactive terminal for docker containers does not work either. It's kernel limitations, according to the link below:

https://stackoverflow.com/questions/52520008/can-i-install-docker-on-arm8-based-synology-nas

Now I'm really thinking of installing linux on my old i386 laptop and replace the arm32 NAS.

qdm12 · 2021-06-27T21:46:28Z

Now I'm really thinking of installing linux on my old i386 laptop and replace the arm32 NAS.

Let's continue the discussion on #80 for that.

For the error you see, my feeling is that there is already something listening on port 53 so the container fails to listen on it. Although it should log out something about it, I'll investigate why.

Anyway, you can try finding if something listens on port 53 with for example lsof -i -P -n | grep LISTEN

woncheol-kim · 2021-06-27T21:55:03Z

For the error you see, my feeling is that there is already something listening on port 53 so the container fails to listen on it. Although it should log out something about it, I'll investigate why.

Anyway, you can try finding if something listens on port 53 with for example lsof -i -P -n | grep LISTEN

My system does not support lsof command, but the old version qmcgaw/cloudflare-dns-server works fine on port 53. Of course I closed the old version before I try the new one.

qdm12 · 2021-06-28T13:46:49Z

It should work with qmcgaw/dns:v1.5.0 as well since it uses alpine 3.12 and since you can't upgrade Docker/libseccomp2 on your host. I'll investigate why v2 doesn't work and get back to you. I will also build you a special image based on Alpine 3.12 too with the latest v1 version.

woncheol-kim · 2021-06-28T14:13:10Z

Thank you. v1.5.0 ends up saying that it does not have permission to open port 53.
Then I've tried with the option --user=root and it seems to work, but it actually partly works: sometimes (or many times) it does not reply to a domain name request.

The messages are as below:

2021/06/28 14:04:40 INFO using DNS address 127.0.0.1 internally
2021/06/28 14:04:40 INFO generating Unbound configuration
2021/06/28 14:04:40 INFO starting unbound
2021/06/28 14:04:40 INFO healthcheck server: listening on 127.0.0.1:9999
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] warning: setrlimit: Operation not permitted
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] warning: cannot increase max open fds from 1024 to 8266
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] warning: continuing with less udp ports: 477
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] warning: increase ulimit or decrease threads, ports in config to remove this warning
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] notice: init module 0: validator
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] notice: init module 1: iterator
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] info: start of service (unbound 1.10.1).
2021/06/28 14:04:40 INFO [1624889080] unbound[13:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
2021/06/28 14:04:40 INFO restarting Unbound the first time to get updated files
2021/06/28 14:04:40 INFO downloading DNSSEC root hints and named root
2021/06/28 14:04:45 INFO downloading and building DNS block lists
2021/06/28 14:04:47 INFO 350398 hostnames blocked overall
2021/06/28 14:04:47 INFO 402 IP addresses blocked overall
2021/06/28 14:04:47 INFO 2490 IP networks blocked overall
2021/06/28 14:04:47 INFO generating Unbound configuration
2021/06/28 14:04:47 INFO starting unbound
2021/06/28 14:04:48 INFO [1624889088] unbound[17:0] warning: setrlimit: Operation not permitted
2021/06/28 14:04:48 INFO [1624889088] unbound[17:0] warning: cannot increase max open fds from 1024 to 8266
2021/06/28 14:04:48 INFO [1624889088] unbound[17:0] warning: continuing with less udp ports: 477
2021/06/28 14:04:48 INFO [1624889088] unbound[17:0] warning: increase ulimit or decrease threads, ports in config to remove this warning
2021/06/28 14:04:52 INFO [1624889092] unbound[17:0] notice: init module 0: validator
2021/06/28 14:04:52 INFO [1624889092] unbound[17:0] notice: init module 1: iterator
2021/06/28 14:04:52 INFO [1624889092] unbound[17:0] info: start of service (unbound 1.10.1).
2021/06/28 14:04:52 INFO [1624889092] unbound[17:1] info: generate keytag query _ta-4a5c-4f66. NULL IN

qdm12 · 2021-06-28T15:47:02Z

Do you see in the logs what's the Unbound version for

qmcgaw/dns:v1.5.0
your older qmcgaw/cloudflare-dns-server image

I see quite a few warnings that I have not seen like setrlimit: Operation not permitted or cannot increase max open fds from 1024 to 8266 🤔

Anyway, give me a few hours, I'll see why v2 doesn't work in your situation. v2 does not depend on anything really, it's just a single binary without even an operating system so it should be working better anyway on corner cases hosts like yours.

woncheol-kim · 2021-06-28T21:32:21Z

Please find below the messages from qmcgaw/cloudflare-dns-server. Surprisingly, it's almost the same: the same unbound 1.10.1, the same 'setrlimit: Operation not permitted' error, 'cannot increase max open fds from 1024 to 8266' error:

2021-06-28T21:25:05.090Z	INFO	healthcheck server: listening on 127.0.0.1:9999
2021-06-28T21:25:05.091Z	INFO	using DNS address 127.0.0.1 internally
2021-06-28T21:25:05.092Z	INFO	generating Unbound configuration
2021-06-28T21:25:05.093Z	INFO	starting unbound
2021-06-28T21:25:05.109Z	INFO	[1624915505] unbound[11:0] warning: setrlimit: Operation not permitted
2021-06-28T21:25:05.109Z	INFO	[1624915505] unbound[11:0] warning: cannot increase max open fds from 1024 to 8266
2021-06-28T21:25:05.109Z	INFO	[1624915505] unbound[11:0] warning: continuing with less udp ports: 477
2021-06-28T21:25:05.110Z	INFO	[1624915505] unbound[11:0] warning: increase ulimit or decrease threads, ports in config to remove this warning
2021-06-28T21:25:05.158Z	INFO	[1624915505] unbound[11:0] notice: init module 0: validator
2021-06-28T21:25:05.170Z	INFO	[1624915505] unbound[11:0] notice: init module 1: iterator
2021-06-28T21:25:05.207Z	INFO	[1624915505] unbound[11:0] info: start of service (unbound 1.10.1).
2021-06-28T21:25:05.463Z	INFO	[1624915505] unbound[11:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
2021-06-28T21:25:05.464Z	INFO	[1624915505] unbound[11:1] info: generate keytag query _ta-4a5c-4f66. NULL IN
2021-06-28T21:25:05.716Z	INFO	restarting Unbound the first time to get updated files
2021-06-28T21:25:05.716Z	INFO	downloading DNSSEC root hints and named root
2021-06-28T21:25:11.502Z	INFO	downloading and building DNS block lists
2021-06-28T21:25:14.837Z	INFO	350398 hostnames blocked overall
2021-06-28T21:25:14.838Z	INFO	2892 IP addresses blocked overall
2021-06-28T21:25:14.838Z	INFO	generating Unbound configuration
2021-06-28T21:25:15.305Z	INFO	starting unbound
2021-06-28T21:25:16.698Z	INFO	[1624915516] unbound[18:0] warning: setrlimit: Operation not permitted
2021-06-28T21:25:16.698Z	INFO	[1624915516] unbound[18:0] warning: cannot increase max open fds from 1024 to 8266
2021-06-28T21:25:16.699Z	INFO	[1624915516] unbound[18:0] warning: continuing with less udp ports: 477
2021-06-28T21:25:16.700Z	INFO	[1624915516] unbound[18:0] warning: increase ulimit or decrease threads, ports in config to remove this warning
2021-06-28T21:25:19.785Z	INFO	[1624915519] unbound[18:0] notice: init module 0: validator
2021-06-28T21:25:19.786Z	INFO	[1624915519] unbound[18:0] notice: init module 1: iterator
2021-06-28T21:25:19.827Z	INFO	[1624915519] unbound[18:0] info: start of service (unbound 1.10.1).
2021-06-28T21:25:22.344Z	INFO	[1624915522] unbound[18:0] info: generate keytag query _ta-4a5c-4f66. NULL IN

qdm12 · 2021-06-29T16:51:23Z

Try :v1.5.1, sorry v1.5.0 had a bug in there I think. I didn't have time to dig into why :v2.0.0-beta doesn't work, maybe try running it with --user="0" (as root)?

woncheol-kim · 2021-06-29T21:40:40Z

Thank you. v.1.5.1 seems to work fine.
And v.2.0.0.-beta with the option --user="0" works well without any error nor warning!

qdm12 · 2021-06-29T21:56:50Z

Alright nice!

It was probably the same error for :v2.0.0-beta where it could not bind to port 53 without root on your system.

On both images, we use libcap to set low port binding capability on the binary (unbound for v1, and the Go program I wrote for v2) with setcap 'cap_net_bind_service=+ep' unbound. This way the container can run by default without root (safer) and have only that capability (low port number binding).

My guess is your older Docker and/or Kernel do not like that fiddling 😉 I've added a warning to the readme advising to run it as root if you run an old Docker or kernel (5b48b7f)

Closing the issue 👍

qdm12 closed this as completed Jun 29, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Failure on arm32 machine #79

Failure on arm32 machine #79

woncheol-kim commented Jun 26, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 26, 2021

woncheol-kim commented Jun 26, 2021

qdm12 commented Jun 27, 2021

woncheol-kim commented Jun 27, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 27, 2021 •

edited

Loading

woncheol-kim commented Jun 27, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 27, 2021

woncheol-kim commented Jun 27, 2021

qdm12 commented Jun 27, 2021 •

edited

Loading

woncheol-kim commented Jun 27, 2021

qdm12 commented Jun 28, 2021

woncheol-kim commented Jun 28, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 28, 2021

woncheol-kim commented Jun 28, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 29, 2021

woncheol-kim commented Jun 29, 2021

qdm12 commented Jun 29, 2021

Failure on arm32 machine #79

Failure on arm32 machine #79

Comments

woncheol-kim commented Jun 26, 2021 • edited by qdm12 Loading

qdm12 commented Jun 26, 2021

woncheol-kim commented Jun 26, 2021

qdm12 commented Jun 27, 2021

woncheol-kim commented Jun 27, 2021 • edited by qdm12 Loading

qdm12 commented Jun 27, 2021 • edited Loading

woncheol-kim commented Jun 27, 2021 • edited by qdm12 Loading

qdm12 commented Jun 27, 2021

woncheol-kim commented Jun 27, 2021

qdm12 commented Jun 27, 2021 • edited Loading

woncheol-kim commented Jun 27, 2021

qdm12 commented Jun 28, 2021

woncheol-kim commented Jun 28, 2021 • edited by qdm12 Loading

qdm12 commented Jun 28, 2021

woncheol-kim commented Jun 28, 2021 • edited by qdm12 Loading

qdm12 commented Jun 29, 2021

woncheol-kim commented Jun 29, 2021

qdm12 commented Jun 29, 2021

woncheol-kim commented Jun 26, 2021 •

edited by qdm12

Loading

woncheol-kim commented Jun 27, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 27, 2021 •

edited

Loading

woncheol-kim commented Jun 27, 2021 •

edited by qdm12

Loading

qdm12 commented Jun 27, 2021 •

edited

Loading

woncheol-kim commented Jun 28, 2021 •

edited by qdm12

Loading

woncheol-kim commented Jun 28, 2021 •

edited by qdm12

Loading