search

Azure / azure-iot-sdk-c

A C99 SDK for connecting devices to Microsoft Azure IoT services
https://azure.github.io/azure-iot-sdk-c
Other
588 stars 737 forks source link

segmentationfault in amqp sample if started without internet connection and afterwards connecting again #184

Closed czyba closed 7 years ago

czyba commented 7 years ago

Hi Azure SDK Team,

I ran into a segfault in the following situation on Debian Jessie and Gentoo Linux. I tested with the current master ( df786d7b1fd167640bb61f0deb9bcc62109ee74b ) and release_2017_07_14. This issue seems similar to the issues #167 and #160, the cause, however, at least from what I can tell from my gdb sessions and traces, seems to be different.

You can reproduce the issue by executing the following steps:

  1. Disconnect from the internet (i.e. by cutting the wireless lan connection)
  2. Start a properly modified iothub_client_sample_x509 (such that the sample would actually work)
  3. Reconnect to the internet after a couple of seconds (after you see the first errors)
  4. Wait for 5-10 Minutes until a Segfault occurs

Note: Disconnecting before starting the program is the key here. If you start the program, wait until the connection to the iothub is established, disconnect from the internet, reconnect again, and wait for a couple of minutes, it will send the remaining enqueued messages just fine.

I was able to reproduce this consistently on both machines. Here is the gdb trace from my gentoo machine. At the bottom you can see the actual line that triggers the segfault and the reason from my print messages:

czyba@X1:~/azure-iot-sdk-c/cmake/iotsdk_linux> gdb ./iothub_client/samples/iothub_client_sample_x509/iothub_client_sample_x509 
GNU gdb (Gentoo 8.0 vanilla) 8.0
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-pc-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://bugs.gentoo.org/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./iothub_client/samples/iothub_client_sample_x509/iothub_client_sample_x509...done.
(gdb) run
Starting program: /home/czyba/azure-iot-sdk-c/cmake/iotsdk_linux/iothub_client/samples/iothub_client_sample_x509/iothub_client_sample_x509 
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Starting the IoTHub client sample x509...
Info: IoT Hub SDK for C, version 1.1.19
Info: Retry policy set (5, timeout = 0)
IoTHubClient_LL_SetMessageCallback...successful.
IoTHubClient_LL_SendEventAsync accepted message [0] for transmission to IoT Hub.
Info: Transport state changed from AMQP_TRANSPORT_STATE_NOT_CONNECTED to AMQP_TRANSPORT_STATE_CONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/c-utility/adapters/socketio_berkeley.c Func:socketio_open Line:626 Failure: getaddrinfo failure -3.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/c-utility/src/tlsio_openssl.c Func:on_underlying_io_open_complete Line:681 Invalid tlsio_state. Expected state is TLSIO_STATE_OPENING_UNDERLYING_IO.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/c-utility/src/tlsio_openssl.c Func:tlsio_openssl_open Line:1195 Failed opening the underlying I/O.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/uamqp/src/connection.c Func:connection_open Line:1253 Opening the underlying IO failed
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:create_event_sender Line:456 Failed opening the AMQP message sender.
IoTHubClient_LL_SendEventAsync accepted message [1] for transmission to IoT Hub.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
IoTHubClient_LL_SendEventAsync accepted message [2] for transmission to IoT Hub.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
IoTHubClient_LL_SendEventAsync accepted message [3] for transmission to IoT Hub.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
IoTHubClient_LL_SendEventAsync accepted message [4] for transmission to IoT Hub.
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:19 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:20 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:26 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:34 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:20:50 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:21:22 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:22:27 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Info: Preparing transport for re-connection
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED to AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION
Info: Transport state changed from AMQP_TRANSPORT_STATE_READY_FOR_RECONNECTION to AMQP_TRANSPORT_STATE_RECONNECTING
Info: Transport state changed from AMQP_TRANSPORT_STATE_RECONNECTING to AMQP_TRANSPORT_STATE_CONNECTED
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 0)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 1)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 2)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 3)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_telemetry_messenger.c Func:process_state_changes Line:1567 messagesender reported unexpected state 4 while messenger is starting
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_device.c Func:device_do_work Line:815 Device 'testdevice' messenger failed to be started (messenger got into error state)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_Device_DoWork Line:996 Failed performing DoWork for device 'testdevice' (device reported state 6; number of previous failures: 4)
Error: Time:Thu Jul 27 15:24:35 2017 File:/home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c Func:IoTHubTransport_AMQP_Common_DoWork Line:1415 Device 'testdevice' reported a critical failure; connection retry will be triggered.
Info: Transport state changed from AMQP_TRANSPORT_STATE_CONNECTED to AMQP_TRANSPORT_STATE_RECONNECTION_REQUIRED
Error: Time:Thu Jul 27 15:28:34 2017 File:/home/czyba/azure-iot-sdk-c/c-utility/src/tlsio_openssl.c Func:tlsio_openssl_send Line:1284 Invalid tlsio_state. Expected state is TLSIO_STATE_OPEN.
Error: Time:Thu Jul 27 15:28:34 2017 File:/home/czyba/azure-iot-sdk-c/uamqp/src/connection.c Func:on_bytes_encoded Line:241 Cannot send encoded bytes
Info: Closing tlsio from a state other than TLSIO_STATE_EXT_OPEN or TLSIO_STATE_EXT_ERROR

Program received signal SIGSEGV, Segmentation fault.
0x0000000000000000 in ?? ()
(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x00000000004703ce in connection_set_state (connection=0x6da8c0, connection_state=CONNECTION_STATE_END) at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:99
#2  0x0000000000470a0d in on_bytes_encoded (context=0x6da8c0, bytes=0x6da230 "", length=81, encode_complete=true) at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:248
#3  0x0000000000475a22 in frame_codec_encode_frame (frame_codec=0x6d5a00, type=0 '\000', payloads=0x6da210, payload_count=1, type_specific_bytes=0x7fffffffd220 "", type_specific_size=2, on_bytes_encoded=0x4708fd <on_bytes_encoded>, callback_context=0x6da8c0)
    at /home/czyba/azure-iot-sdk-c/uamqp/src/frame_codec.c:682
#4  0x000000000048202a in amqp_frame_codec_encode_frame (amqp_frame_codec=0x6d7a90, channel=0, performative=0x6d8e20, payloads=0x0, payload_count=0, on_bytes_encoded=0x4708fd <on_bytes_encoded>, callback_context=0x6da8c0)
    at /home/czyba/azure-iot-sdk-c/uamqp/src/amqp_frame_codec.c:310
#5  0x0000000000471379 in send_close_frame (connection=0x6da8c0, error_handle=0x6d9220) at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:443
#6  0x000000000047158f in close_connection_with_error (connection=0x6da8c0, condition_value=0x49df63 "amqp:internal-error", description=0x49e548 "No frame received for the idle timeout") at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:496
#7  0x0000000000473ce4 in connection_handle_deadlines (connection=0x6da8c0) at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:1581
#8  0x0000000000473ec6 in connection_dowork (connection=0x6da8c0) at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:1634
#9  0x0000000000446d05 in amqp_connection_do_work (conn_handle=0x6da140) at /home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_connection.c:437
#10 0x000000000043f72d in IoTHubTransport_AMQP_Common_DoWork (handle=0x6d4930, iotHubClientHandle=0x6d4770) at /home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransport_amqp_common.c:1429
#11 0x000000000043ccda in IoTHubTransportAMQP_DoWork (handle=0x6d4930, iotHubClientHandle=0x6d4770) at /home/czyba/azure-iot-sdk-c/iothub_client/src/iothubtransportamqp.c:66
#12 0x00000000004178ec in IoTHubClient_LL_DoWork (iotHubClientHandle=0x6d4770) at /home/czyba/azure-iot-sdk-c/iothub_client/src/iothub_client_ll.c:1148
#13 0x000000000041362f in main () at /home/czyba/azure-iot-sdk-c/iothub_client/samples/iothub_client_sample_x509/iothub_client_sample_x509.c:271
(gdb) up
#1  0x00000000004703ce in connection_set_state (connection=0x6da8c0, connection_state=CONNECTION_STATE_END) at /home/czyba/azure-iot-sdk-c/uamqp/src/connection.c:99
99              connection->endpoints[i]->on_connection_state_changed(connection->endpoints[i]->callback_context, connection_state, previous_state);
(gdb) l
94
95          /* Codes_SRS_CONNECTION_01_260: [Each endpoint's on_connection_state_changed shall be called.] */
96          for (i = 0; i < connection->endpoint_count; i++)
97          {
98              /* Codes_SRS_CONNECTION_01_259: [The callback_context passed in connection_create_endpoint.] */
99              connection->endpoints[i]->on_connection_state_changed(connection->endpoints[i]->callback_context, connection_state, previous_state);
100         }
101     }
102
103     static int send_header(CONNECTION_HANDLE connection)
(gdb) p connection->endpoints[i]
$1 = (ENDPOINT_INSTANCE *) 0x6d4540
(gdb) p connection->endpoints[i].on_connection_state_changed
$2 = (ON_CONNECTION_STATE_CHANGED) 0x0

I hope this helps. Kind regards Christopher Czyba

czyba commented 7 years ago

I was able to reproduce this issue as well in another situation:

  1. Connected to the internet
  2. Start a properly modified iothub_client_sample_x509 (such that the sample would actually work)
  3. Disconnect from the internet
  4. Wait for the first "reconnection" to occur. ( This will take 5-10 minutes )
  5. Reconnect to the internet
  6. Wait for a while till the segmentation fault occurs.
ewertons commented 7 years ago

Hi @czyba , thanks for reporting this issue. Let me compare with our connection tests and verify if I get a repro. Good that you attached the callstack already, really appreciated.

ewertons commented 7 years ago

Hi @czyba, a fix was just checked in for this sample, please verify if you have a chance and let us know. Thanks, Azure IoT Team.

czyba commented 7 years ago

Hi @ewertons,

it works on my end. Thanks.