I have an issue with CreateFromEnvironment.
OS and version used: NAME="Ubuntu"
VERSION="18.04.2 LTS (Bionic Beaver)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 18.04.2 LTS"
VERSION_ID="18.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=bionic
UBUNTU_CODENAME=bionic
Description of the issue:
I am developing an iot edge module. Up to now I provided the connection string for the module which I got from the device management in the azure portal. So, there were two connection strings, one for the egde device in the config.yaml and one for the module. This worked. As I don't want to provide the module string, I wanted to use the CreateFromEnvironment method. This fails with an exception, every time. Code sample exhibiting the issue:
App.LogInfo("Start to create client with MQTT protocol, CS=" + sConnString);
m_client = ModuleClient.createFromEnvironment(IotHubClientProtocol.MQTT);
App.LogInfo("Client created");
// Set the callback for messages
m_client.setMessageCallback(INPUT_NAME, new MessageCallback()
{
/* ... */
}
}, m_client);
// Register the callback for connection state change
m_client.registerConnectionStatusChangeCallback(new IotHubConnectionStatusChangeCallback ()
{ /* ... */
{
}, null);
// Open client
m_client.open();
Console log of the issue:
1082 [main] INFO HbIIoTGateway - Start to create client with MQTT protocol, CS=
1724 [main] INFO HbIIoTGateway - Client created
1976 [main] ERROR HbIIoTGateway - java.io.IOException: Could not open the connection
Stacktrace:
java.io.IOException: Could not open the connection
at com.microsoft.azure.sdk.iot.device.DeviceIO.open(DeviceIO.java:162)
at com.microsoft.azure.sdk.iot.device.InternalClient.open(InternalClient.java:123)
at com.edgemodule.AzureConnection.<init>(AzureConnection.java:197)
at com.edgemodule.HbIIotMsgHandler.reconnectAzure(HbIIotMsgHandler.java:171)
at com.edgemodule.HbIIotConfigHandler.doWork(HbIIotConfigHandler.java:126)
at com.edgemodule.App.main(App.java:99)
Caused by: com.microsoft.azure.sdk.iot.device.exceptions.ProtocolException: Unable to establish MQTT connection
at com.microsoft.azure.sdk.iot.device.transport.mqtt.exceptions.PahoExceptionTranslator.convertToMqttException(PahoExceptionTranslator.java:47)
at com.microsoft.azure.sdk.iot.device.transport.mqtt.Mqtt.connect(Mqtt.java:130)
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttMessaging.start(MqttMessaging.java:57)
at com.microsoft.azure.sdk.iot.device.transport.mqtt.MqttIotHubConnection.open(MqttIotHubConnection.java:187)
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.openConnection(IotHubTransport.java:707)
at com.microsoft.azure.sdk.iot.device.transport.IotHubTransport.open(IotHubTransport.java:273)
at com.microsoft.azure.sdk.iot.device.DeviceIO.open(DeviceIO.java:158)
... 5 more
Caused by: MqttException (0) - java.lang.IllegalArgumentException: Contains non-LDH ASCII characters
at org.eclipse.paho.client.mqttv3.internal.ExceptionHelper.createMqttException(ExceptionHelper.java:38)
at org.eclipse.paho.client.mqttv3.internal.ClientComms$ConnectBG.run(ClientComms.java:736)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalArgumentException: Contains non-LDH ASCII characters
at java.net.IDN.toASCIIInternal(IDN.java:296)
at java.net.IDN.toASCII(IDN.java:122)
at javax.net.ssl.SNIHostName.<init>(SNIHostName.java:99)
at org.eclipse.paho.client.mqttv3.internal.SSLNetworkModule.start(SSLNetworkModule.java:139)
at org.eclipse.paho.client.mqttv3.internal.ClientComms$ConnectBG.run(ClientComms.java:722)
... 1 more
Environment in container:
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/lib/jvm/java-1.8-openjdk/jre/bin:/usr/lib/jvm/java-1.8-openjdk/bin
HOSTNAME=ee818de81f64
IOTEDGE_WORKLOADURI=unix:///var/run/iotedge/workload.sock
IOTEDGE_MODULEID=hb_azure_gw
IOTEDGE_GATEWAYHOSTNAME=peers_docker_dev
IOTEDGE_AUTHSCHEME=sasToken
RuntimeLogLevel=Debug
IOTEDGE_DEVICEID=MyDevId
IOTEDGE_IOTHUBHOSTNAME=XXX.azure-devices.net
IOTEDGE_MODULEGENERATIONID=637110536099764761
IOTEDGE_APIVERSION=2019-01-30
LANG=C.UTF-8
JAVA_HOME=/usr/lib/jvm/java-1.8-openjdk
JAVA_VERSION=8u191
JAVA_ALPINE_VERSION=8.191.12-r0
HOME=/home/moduleuser
IOT Edge status:
iotedge.service - Azure IoT Edge daemon
Loaded: loaded (/lib/systemd/system/iotedge.service; enabled; vendor preset: enabled)
Active: active (running) since Fri 2020-01-31 07:07:07 UTC; 1min 50s ago
Docs: man:iotedged(8)
Main PID: 25939 (iotedged)
Tasks: 9 (limit: 9466)
CGroup: /system.slice/iotedge.service
└─25939 /usr/bin/iotedged -c /etc/iotedge/config.yaml
Jan 31 07:08:39 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:39Z [INFO] - [work] - - - [2020-01-31 07:08:39.171640824 UTC] "POST /modules/hb_azure_gw/genid/637110536099764761/sign?api-version=2018
Jan 31 07:08:39 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:39Z [INFO] - [work] - - - [2020-01-31 07:08:39.175033336 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" a
Jan 31 07:08:40 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:40Z [INFO] - [mgmt] - - - [2020-01-31 07:08:40.920544225 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1570 "-" "-" auth_i
Jan 31 07:08:45 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:45Z [INFO] - [mgmt] - - - [2020-01-31 07:08:45.949577894 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1570 "-" "-" auth_i
Jan 31 07:08:46 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:46Z [INFO] - [work] - - - [2020-01-31 07:08:46.356573243 UTC] "POST /modules/hb_azure_gw/genid/637110536099764761/sign?api-version=2018
Jan 31 07:08:46 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:46Z [INFO] - [work] - - - [2020-01-31 07:08:46.364147733 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" a
Jan 31 07:08:50 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:50Z [INFO] - [work] - - - [2020-01-31 07:08:50.472441217 UTC] "POST /modules/hb_azure_gw/genid/637110536099764761/sign?api-version=2018
Jan 31 07:08:50 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:50Z [INFO] - [work] - - - [2020-01-31 07:08:50.473865172 UTC] "GET /trust-bundle?api-version=2018-06-28 HTTP/1.1" 200 OK 1944 "-" "-" a
Jan 31 07:08:50 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:50Z [INFO] - [mgmt] - - - [2020-01-31 07:08:50.979222706 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1570 "-" "-" auth_i
Jan 31 07:08:55 peers_docker_dev iotedged[25939]: 2020-01-31T07:08:55Z [INFO] - [mgmt] - - - [2020-01-31 07:08:55.996628238 UTC] "GET /modules?api-version=2019-01-30 HTTP/1.1" 200 OK 1570 "-" "-" auth_i
~
Module versions:
EdgeHub Version: Version - 1.0.8.4.26769994
EdgeAgent Version:Version - 1.0.8.4.26769994
Update 1: I tried removing the underscores from the module name (hb_azure_gw --> hbazuregw), as I thought the exception points to such a problem. But that didn't fix it. Same problem.
Update 2: I also changed the hostname accoringly, so the iotedge check command now gives this. Certificate warning should not be a problem, right?
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 - OK
‼ production readiness: certificates - Warning
Device is using self-signed, automatically generated certs.
Please see https://aka.ms/iotedge-prod-checklist-certs for best practices.
√ production readiness: certificates expiry - OK
√ production readiness: container engine - OK
√ production readiness: logs policy - OK
Connectivity checks
-------------------
√ 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 - OK
√ container on the default network can connect to IoT Hub HTTPS / WebSockets port - OK
√ container on the default network can connect to IoT Hub MQTT port - OK
√ container on the IoT Edge module network can connect to IoT Hub AMQP port - OK
√ container on the IoT Edge module network can connect to IoT Hub HTTPS / WebSockets port - OK
√ container on the IoT Edge module network can connect to IoT Hub MQTT port - OK
√ Edge Hub can bind to ports on host - OK
22 check(s) succeeded.
1 check(s) raised warnings.
Update 3: When the mentioned error occurs, a TLS-Error is shown in the edgeHub logs.
<7> 2020-02-04 06:45:20.481 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
<7> 2020-02-04 06:45:20.481 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
<4> 2020-02-04 06:45:21.021 +00:00 [WRN] [EdgeHub] - TLS handshake failed., System.IO.IOException: Channel is closed, 04a0890b
<7> 2020-02-04 06:45:30.480 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Getting next batch for endpoint iothub starting from 0 with batch size 100.
<7> 2020-02-04 06:45:30.480 +00:00 [DBG] [Microsoft.Azure.Devices.Edge.Hub.Core.Storage.MessageStore] - Obtained next batch for endpoint iothub with batch size 0. Next start offset = 0.
Do you have any idea what I am doing wrong?
Thanks a lot!
Best regards,
Peer
