Iotedge: Errors running iotedge check w/proxy enabled

[Lexmark-pcarey]

Expected Behavior

When a proxy is configured correctly, iotedge check should not indicate connectivity errors. We're using a basic SQUID proxy using basic auth -- nothing fancy.

Current Behavior

iotedge check indicates connectivity issues, but everything seems to be working just fine. In our case, we use AMQP and MQTT over websockets, so I've been testing this by disabling port 443 by using the following iptables commands:

iptables -A OUTPUT -p tcp --dport 443 -j DROP
iptables -I DOCKER-USER -p tcp --dport 443 -j DROP

Apart from itoedge check results, everything appears to be working per the documentation

Steps to Reproduce

Provide a detailed set of steps to reproduce the bug.

1. Configure a proxy for docker and iotedged, per documentation.
2. Edit config.yaml to include the proxy for edgeAgent
3. Update deployment manifest to include the proxy for edgeWeb
4. Run iotedge check

Context (Environment)

Output of iotedge check

Click here

root@machine:~# iotedge check -c /var/lib/iotedge/config.yaml 
Configuration checks
--------------------
√ config.yaml is well-formed - OK
√ config.yaml has well-formed connection string - OK
√ container engine is installed and functional - OK
√ config.yaml has correct hostname - OK
√ config.yaml has correct URIs for daemon mgmt endpoint - OK
√ latest security daemon - OK
√ host time is close to real time - OK
√ container time is close to host time - OK
‼ DNS server - Warning
    Container engine is not configured with DNS server setting, which may impact connectivity to IoT Hub.
    Please see https://aka.ms/iotedge-prod-checklist-dns for best practices.
    You can ignore this warning if you are setting DNS server per module in the Edge deployment.
√ production readiness: identity certificates expiry - OK
√ production readiness: certificates - OK
‼ production readiness: container engine - Warning
    Device is not using a production-supported container engine (moby-engine).
    Please see https://aka.ms/iotedge-prod-checklist-moby for details.
‼ production readiness: logs policy - Warning
    Container engine is not configured to rotate module logs which may cause it run out of disk space.
    Please see https://aka.ms/iotedge-prod-checklist-logs for best practices.
    You can ignore this warning if you are setting log policy per module in the Edge deployment.
‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning
    The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.
‼ production readiness: Edge Hub's storage directory is persisted on the host filesystem - Warning
    The edgeHub module is not configured to persist its /tmp/edgeHub directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.

Connectivity checks
-------------------
× host can connect to and perform TLS handshake with DPS endpoint - Error
    Could not connect: unsuccessful tunnel
√ host can connect to and perform TLS handshake with IoT Hub AMQP port - OK
√ host can connect to and perform TLS handshake with IoT Hub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with IoT Hub MQTT port - OK
× container on the default network can connect to IoT Hub AMQP port - Error
    Container on the default network could not connect to our-hub.azure-devices.net:5671
× container on the default network can connect to IoT Hub HTTPS / WebSockets port - Error
    Container on the default network could not connect to our-hub.azure-devices.net:443
× container on the default network can connect to IoT Hub MQTT port - Error
    Container on the default network could not connect to our-hub.azure-devices.net:8883
× container on the IoT Edge module network can connect to IoT Hub AMQP port - Error
    Container on the azure-iot-edge network could not connect to our-hub.azure-devices.net:5671
× container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - Error
    Container on the azure-iot-edge network could not connect to our-hub.azure-devices.net:443
× container on the IoT Edge module network can connect to IoT Hub MQTT port - Error
    Container on the azure-iot-edge network could not connect to our-hub.azure-devices.net:8883

13 check(s) succeeded.
5 check(s) raised warnings. Re-run with --verbose for more details.
7 check(s) raised errors. Re-run with --verbose for more details.

Device Information

• Host OS: Linux (Poky. Dunfell)
• Architecture: arm64
• Container OS: Linux

Runtime Versions

• aziot-edged: 1.1.1
• Edge Agent: 1.1.1
• Edge Hub: 1.1.1
• Docker/Moby: 19.03.8-ce

Logs

aziot-edged logs

May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Initializing hsm...
May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Finished initializing hsm.
May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Initializing hsm X509 interface...
May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Detected HTTPS proxy server http://****:****@192.168.7.102:3128/
May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Finished initializing hsm X509 interface...
May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Provisioning edge device...
May 13 18:41:13 machine iotedged[8016]: 2021-05-13T18:41:13Z [INFO] - Starting provisioning edge device via X509 provisioning...

edge-agent logs

May 13 18:41:26 machine mcr.microsoft.com/azureiotedge-agent:1.1.1[342]: 2021-05-13 18:41:26.010 +00:00 Edge Agent Main()
May 13 18:41:26 machine mcr.microsoft.com/azureiotedge-agent:1.1.1[342]: <6> 2021-05-13 18:41:26.875 +00:00 [INF] - Initializing Edge Agent.
May 13 18:41:27 machine mcr.microsoft.com/azureiotedge-agent:1.1.1[342]: <6> 2021-05-13 18:41:27.624 +00:00 [INF] - Version - 1.1.1.40522521 (27369573a0c04f9c2deeaf1ba4198a7efb8e4604)
// Figlet font elided
May 13 18:41:27 machine mcr.microsoft.com/azureiotedge-agent:1.1.1[342]: <6> 2021-05-13 18:41:27.693 +00:00 [INF] - Detected proxy http://****:****@192.168.7.102:3128/
May 13 18:41:27 machine mcr.microsoft.com/azureiotedge-agent:1.1.1[342]: <6> 2021-05-13 18:41:27.838 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false}

edge-hub logs

May 13 18:41:42 machine mcr.microsoft.com/azureiotedge-hub:1.1.1[342]: <6> 2021-05-13 18:41:42.526 +00:00 [INF] - Enabling SSL protocols: Tls, Tls11, Tls12
May 13 18:41:43 machine mcr.microsoft.com/azureiotedge-hub:1.1.1[342]: <6> 2021-05-13 18:41:43.124 +00:00 [INF] - Experimental features configuration: {"Enabled":false,"DisableCloudSubscriptions":false,"DisableConnectivityCheck":false}
May 13 18:41:43 machine mcr.microsoft.com/azureiotedge-hub:1.1.1[342]: <6> 2021-05-13 18:41:43.876 +00:00 [INF] - Detected proxy http://****:****@192.168.7.102:3128/

Additional Information

Here are the SQUID (proxy) access logs when iotedge check is run:

1620958751.218      1 192.168.7.60 TAG_NONE/503 0 CONNECT https:443 username HIER_NONE/- -
1620958751.467    152 192.168.7.60 TCP_TUNNEL/200 3980 CONNECT our-hub-devices.net:5671 username HIER_DIRECT/104.211.18.153 -
1620958751.670    108 192.168.7.60 TCP_TUNNEL/200 3950 CONNECT our-hub-devices.net:443 username HIER_DIRECT/104.211.18.153 -
1620958751.876    111 192.168.7.60 TCP_TUNNEL/200 3980 CONNECT our-hub-devices.net:8883 username HIER_DIRECT/104.211.18.153 -
1620958753.725      0 192.168.7.60 TAG_NONE/400 4411 CONNECT our-hub-devices.net:5671 - HIER_NONE/- text/html
1620958756.259      0 192.168.7.60 TAG_NONE/400 4410 CONNECT our-hub-devices.net:443 - HIER_NONE/- text/html
1620958758.850      0 192.168.7.60 TAG_NONE/400 4411 CONNECT our-hub-devices.net:8883 - HIER_NONE/- text/html
1620958761.720      0 192.168.7.60 TAG_NONE/400 4411 CONNECT our-hub-devices.net:5671 - HIER_NONE/- text/html
1620958764.639      0 192.168.7.60 TAG_NONE/400 4410 CONNECT our-hub-devices.net:443 - HIER_NONE/- text/html
1620958767.479      0 192.168.7.60 TAG_NONE/400 4411 CONNECT our-hub-devices.net:8883 - HIER_NONE/- text/html

I am no expert in network proxies, but according to SQUID's documentation, could the dash in "our-hub-devices.net:5671 - HIER_NONE" indicate that no username was available for proxy authentication (a very wild guess)?

Thanks in advance for any help!

[dylanbronson]

Hello,
I've taken a look at the diagnostics module code, and it seems like we could potentially have a bug when it comes to basic auth, but I am not positive yet. Can you please run command again but this time with the verbose flag turned on?
--verbose
Also, when you say basic auth, do you mean that you are using the format where you add your username and password as part of the http_proxy string in the config.yaml?

[Lexmark-pcarey]

Thanks for the feedback.

I am using the http://username:password@proxy-addr:3128 format for basic auth (what's configured on the proxy).

Here are the verbose results of itoedge check:

root@machine:~# iotedge check --verbose -c /var/lib/iotedge/config.yaml 
Configuration checks
--------------------
√ config.yaml is well-formed - OK
√ config.yaml has well-formed connection string - OK
√ container engine is installed and functional - OK
√ config.yaml has correct hostname - OK
√ config.yaml has correct URIs for daemon mgmt endpoint - OK
√ latest security daemon - OK
√ host time is close to real time - OK
√ container time is close to host time - OK
‼ DNS server - Warning
    Container engine is not configured with DNS server setting, which may impact connectivity to IoT Hub.
    Please see https://aka.ms/iotedge-prod-checklist-dns for best practices.
    You can ignore this warning if you are setting DNS server per module in the Edge deployment.
        caused by: Could not open container engine config file /etc/docker/daemon.json
        caused by: No such file or directory (os error 2)
√ production readiness: identity certificates expiry - OK
√ production readiness: certificates - OK
‼ production readiness: container engine - Warning
    Device is not using a production-supported container engine (moby-engine).
    Please see https://aka.ms/iotedge-prod-checklist-moby for details.
‼ production readiness: logs policy - Warning
    Container engine is not configured to rotate module logs which may cause it run out of disk space.
    Please see https://aka.ms/iotedge-prod-checklist-logs for best practices.
    You can ignore this warning if you are setting log policy per module in the Edge deployment.
        caused by: Could not open container engine config file /etc/docker/daemon.json
        caused by: No such file or directory (os error 2)
‼ production readiness: Edge Agent's storage directory is persisted on the host filesystem - Warning
    The edgeAgent module is not configured to persist its /tmp/edgeAgent directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.
‼ production readiness: Edge Hub's storage directory is persisted on the host filesystem - Warning
    The edgeHub module is not configured to persist its /tmp/edgeHub directory on the host filesystem.
    Data might be lost if the module is deleted or updated.
    Please see https://aka.ms/iotedge-storage-host for best practices.

Connectivity checks
-------------------
× host can connect to and perform TLS handshake with DPS endpoint - Error
    Could not connect: unsuccessful tunnel
√ host can connect to and perform TLS handshake with IoT Hub AMQP port - OK
√ host can connect to and perform TLS handshake with IoT Hub HTTPS / WebSockets port - OK
√ host can connect to and perform TLS handshake with IoT Hub MQTT port - OK
× container on the default network can connect to IoT Hub AMQP port - Error
    Container on the default network could not connect to our-hub.azure-devices.net:5671
        caused by: docker returned exit code: 1, stderr = One or more errors occurred. (Proxy destination ::ffff:192.168.7.102 on port 3128 responded with a 400 code - Bad Request)
× container on the default network can connect to IoT Hub HTTPS / WebSockets port - Error
    Container on the default network could not connect to our-hub.azure-devices.net:443
        caused by: docker returned exit code: 1, stderr = One or more errors occurred. (Proxy destination ::ffff:192.168.7.102 on port 3128 responded with a 400 code - Bad Request)
× container on the default network can connect to IoT Hub MQTT port - Error
    Container on the default network could not connect to our-hub.azure-devices.net:8883
        caused by: docker returned exit code: 1, stderr = One or more errors occurred. (Proxy destination ::ffff:192.168.7.102 on port 3128 responded with a 400 code - Bad Request)
× container on the IoT Edge module network can connect to IoT Hub AMQP port - Error
    Container on the azure-iot-edge network could not connect to our-hub.azure-devices.net:5671
        caused by: docker returned exit code: 1, stderr = One or more errors occurred. (Proxy destination ::ffff:192.168.7.102 on port 3128 responded with a 400 code - Bad Request)
× container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - Error
    Container on the azure-iot-edge network could not connect to our-hub.azure-devices.net:443
        caused by: docker returned exit code: 1, stderr = One or more errors occurred. (Proxy destination ::ffff:192.168.7.102 on port 3128 responded with a 400 code - Bad Request)
× container on the IoT Edge module network can connect to IoT Hub MQTT port - Error
    Container on the azure-iot-edge network could not connect to our-hub.azure-devices.net:8883
        caused by: docker returned exit code: 1, stderr = One or more errors occurred. (Proxy destination ::ffff:192.168.7.102 on port 3128 responded with a 400 code - Bad Request)

13 check(s) succeeded.
5 check(s) raised warnings.
7 check(s) raised errors.

[dylanbronson]

Hello, I have an update for you!
There are two different issues going on here.
Firstly, iotedge check shouldn't be running for mqtt or amqp when we use a proxy. It's expected to fail, which is misleading. I've created a bug for this.
Secondly, we have a bug where we fail for WebSockets for proxy when we should succeed. I've fixed this in a PR.

Both of these fixes should go in the next release. I will update here.

[dylanbronson]

Hello, we have released version 1.1.3 https://github.com/Azure/iotedge/releases/tag/1.1.3
The WebSockets fix made it in, but the fix for not running the mqtt or amqp when using a proxy is still being worked on. Feel free to try out the new version!