Random crashes with basic pubsub sample

0x6c23 commented 2 years ago

Confirm by changing [ ] to [x] below:

[X] I've searched for previous similar issues and didn't find any solution

Known Issue

[x] I'm using ATS data type endpoint: the endpoint should look like <prefix>-ats.iot.<region>.amazonaws.com

Platform/OS/Device What are you running the sdk on? Windows 10

Describe the question

I am basically running the basic pub sub sample:

    ApiHandle apiHandle;

    String appdataFolder = getenv("APPDATA");
    String certsFolder = appdataFolder + "\\player\\certs\\";

    String endpoint;
    bool gotEndpoint = this->appConfig->read("IOT.endpointAddress", endpoint);

    String iotDeviceId;
    bool gotIotDeviceId = this->appConfig->read("HWINFO.shortSerial", iotDeviceId);

    if(!gotEndpoint || !gotIotDeviceId) {
        Logger::Critical("Could not get endpointAddress or iotDeviceId from config.");
        exit(-1);
    }

    String certificatePath = certsFolder + iotDeviceId + ".crt";
    String keyPath = certsFolder + iotDeviceId + ".key";
    String caFile = certsFolder + "RootCA1.pem";

    std::string topic("+/"+ iotDeviceId +"/message"); // IotDisplayId
    this->clientId = iotDeviceId; // IotDisplayId

    Io::EventLoopGroup eventLoopGroup(1);
    if (!eventLoopGroup) {
        Logger::Critical("Event Loop Group Creation failed with error ");
        Logger::Critical(ErrorDebugString(eventLoopGroup.LastError()));
        exit(-1);
    }

    Aws::Crt::Io::DefaultHostResolver defaultHostResolver(eventLoopGroup, 1, 5);
    Io::ClientBootstrap bootstrap(eventLoopGroup, defaultHostResolver);

    if (!bootstrap) {
        Logger::Critical("ClientBootstrap failed with error ");
        Logger::Critical(ErrorDebugString(bootstrap.LastError()));
        exit(-1);
    }

    Aws::Iot::MqttClientConnectionConfigBuilder builder;
    builder = Aws::Iot::MqttClientConnectionConfigBuilder(certificatePath.c_str(), keyPath.c_str());
    builder.WithCertificateAuthority(caFile.c_str());
    builder.WithEndpoint(endpoint);

    auto clientConfig = builder.Build();
    if (!clientConfig) {
        Logger::Critical("Client Configuration initialization failed with error ");
        Logger::Critical(ErrorDebugString(clientConfig.LastError()));
        exit(-1);
    }

    /*
    * Create Aws::Iot::MqttClient
    */
    Aws::Iot::MqttClient mqttClient(bootstrap);
    if (!mqttClient) {
        Logger::Critical("MQTT Client Creation failed with error ");
        Logger::Critical(ErrorDebugString(mqttClient.LastError()));
        exit(-1);
    }

    auto connection = mqttClient.NewConnection(clientConfig);
    if (!connection) {
        Logger::Critical("MQTT Connection Creation failed with error ");
        Logger::Critical(ErrorDebugString(mqttClient.LastError()));
        exit(-1);
    }
    //
    this->Connect(connection);
}

Random crashes happen always after 5-10 minutes. The stack is always the same:

Logs before the crash:

[TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: running scheduled tasks. [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [task-scheduler] - id=00000202FF70D388: Running mqtt_ping task with status [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: Sending PING [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: Starting ping [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: Currently not in the event-loop thread, scheduling a task to send message id 2. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: scheduling task with wrapper task id 00000202FF72B210. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: scheduling task 00000202FF72B210 in-thread for timestamp 0 [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [task-scheduler] - id=00000202FF72B210: Scheduling mqtt_outgoing_request_task task for immediate execution [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: Starting ping with packet id 2 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: Scheduling PING. current timestamp is 682511137415000 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: The next ping will be run at timestamp 683511137415000 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: scheduling task with wrapper task id 00000202FF70D388. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: scheduling task 00000202FF70D388 in-thread for timestamp 683511137415000 [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [task-scheduler] - id=00000202FF70D388: Scheduling mqtt_ping task for future execution at time 683511137415000 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: detected more scheduled tasks with the next occurring at 0, using timeout of 0. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: waiting for a maximum of 0 ms [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: running scheduled tasks. [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [task-scheduler] - id=00000202FF72B210: Running mqtt_outgoing_request_task task with status [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: pingreq send [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: acquired message 00000202FF543690 of capacity 3 from pool 000002028046B4D0. Requested size was 3 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: Acquiring memory from pool of required_length 3 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: sending write message of size 2, from slot 00000202804F8C90 to slot 00000202FF690F80 with handler 000002028039DD80. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [tls-handler] - id=000002028039DD80: processing ougoing message of size 2 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [tls-handler] - id=000002028039DD80: processing message fragment of size 2 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: acquired message 00000202FF5447D0 of capacity 31 from pool 000002028046B4D0. Requested size was 31 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [tls-handler] - id=000002028039DD80:message fragment encrypted successfully: size is 31 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: sending write message of size 31, from slot 00000202FF690F80 to slot 00000202FF691340 with handler 00000202803C79F0. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket-handler] - id=00000202803C79F0: writing message of size 31 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket] - id=00000202801B6770 handle=000000000000060C: queueing write of 31 bytes [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: scheduling task with wrapper task id 000002028F1D6490. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: scheduling task 000002028F1D6490 in-thread for timestamp 682514137798200 [DEBUG] [2022-01-09T11:14:40Z] [0000647c] [task-scheduler] - id=000002028F1D6490: Scheduling mqtt_pingresp_timeout task for future execution at time 682514137798200 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [mqtt-client] - id=00000202FF70D1C0: sending request 2 complete, invoking on_complete callback. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: detected more scheduled tasks with the next occurring at 682514137798200, using timeout of 2999. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: waiting for a maximum of 2999 ms [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: wake up with 1 events to process. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: invoking handler. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket] - id=00000202801B6770 handle=000000000000060C: Write Completion callback triggered [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket] - id=00000202801B6770 handle=000000000000060C: Write of size 31 completed [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket-handler] - static: write of size 31, completed on channel 0000020280456330 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: running scheduled tasks. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: detected more scheduled tasks with the next occurring at 682514137798200, using timeout of 2999. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: waiting for a maximum of 2999 ms [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: wake up with 1 events to process. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: invoking handler. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket] - id=00000202801B6770 handle=000000000000060C: socket readable event triggered [ERROR] [2022-01-09T11:14:40Z] [0000647c] [socket] - id=00000202801B6770 handle=000000000000060C: socket status error -1073741508 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket-handler] - id=00000202803C79F0: socket is now readable [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket-handler] - id=00000202803C79F0: invoking read. Downstream window 18446744073709551615, max_to_read 16384 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: acquired message 0000020280460800 of capacity 16384 from pool 000002028046B4D0. Requested size was 16384 [ERROR] [2022-01-09T11:14:40Z] [0000647c] [socket] - id=00000202801B6770 handle=000000000000060C: Attempt to read from an unconnected socket. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [socket-handler] - id=00000202FF691360: total read on this tick 0 [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: channel shutdown task is scheduled [TRACE] [2022-01-09T11:14:40Z] [0000647c] [channel] - id=0000020280456330: scheduling task with wrapper task id 0000020280456510. [TRACE] [2022-01-09T11:14:40Z] [0000647c] [event-loop] - id=00000202FF6EE770: scheduling task 0000020280456510 in-thread for timestamp 0 [DEBUG] [2022-01-09T11:14:40ZException: Exception 0xc0000005 encountered at address 0x7ff73258194b: Access violation reading location 0x00000599

bretambrose commented 2 years ago

ApiHandle is the library lifecycle object. If it goes out of scope (like it appears to here), you will likely have crashes.

jmklix commented 2 years ago

As bretambrose mentioned if ApiHandle goes out of scope, if you try to do anything after that it will crash. Near the bottom of the example you can see the use of promises to wait until it is done sending and receiving messages. Can you try adding this to your code and see if that resolves your crashes?

github-actions[bot] commented 2 years ago

Greetings! It looks like this issue hasn’t been active in longer than a week. We encourage you to check if this is still an issue in the latest release. Because it has been longer than a week since the last update on this, and in the absence of more information, we will be closing this issue soon. If you find that this is still a problem, please feel free to provide a comment or add an upvote to prevent automatic closure, or if the issue is already closed, please feel free to open a new one.

aws / aws-iot-device-sdk-cpp-v2

Random crashes with basic pubsub sample #370