AWS MQTT Python awsiotsdk 和 awscrt 包偶尔会失败，并在跟踪日志中重复消息
AWS MQTT Python awsiotsdk and awscrt packages fail sporadically with repeating messages in trace logs
我正在相当接近 awsiotsdk 包中的 pub/sub example。我的基本单元测试有时成功有时失败。
我使用 awscrt.io.init_logging(6, 'stderr')
启用了跟踪记录
当我查看跟踪日志时，它们看起来相对类似于这一行：
[TRACE] [2021-06-16T23:56:36Z] [00007f5fcfbbc640] [mqtt-topic-tree] - tree=0x5565ac073898: Publishing on topic test/unittest
在那之后，失败的 运行 开始循环生成以下输出，直到我的单元测试在 30 秒后超时：
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolving host #############-ats.iot.us-west-2.amazonaws.com
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 34.213.168.191
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 52.35.137.184
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 54.148.88.142
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 34.214.249.117
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 54.186.43.162
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 52.38.221.226
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 54.244.33.231
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 34.218.88.107
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::23a6:36ae
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::3424:419e
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::22d2:b01f
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::22d7:fa17
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::6415:4c4c
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::2351:30a6
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::3421:1d4e
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::342b:929
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static, resolving host #############-ats.iot.us-west-2.amazonaws.com successful, returned 16 addresses
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 34.213.168.191 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 52.35.137.184 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 54.148.88.142 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 34.214.249.117 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 54.186.43.162 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 52.38.221.226 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 54.244.33.231 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 34.218.88.107 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::23a6:36ae for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::3424:419e for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::22d2:b01f for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::22d7:fa17 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::6415:4c4c for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::2351:30a6 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::3421:1d4e for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::342b:929 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: remaining record count for host 7
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: remaining record count for host 8
A 运行 成功从 Publishing on topic test/unittest 消息继续：
[TRACE] [2021-06-16T23:56:36Z] [00007f5fcfbbc640] [mqtt-client] - id=0x5565ac073640: publish received with msg id=1 dup=0 qos=1 retain=0 payload-size=16 topic=test/unittest
[TRACE] [2021-06-16T23:56:36Z] [00007f5fcfbbc640] [mqtt-client] - id=0x5565ac073640: received publish QOS is 1, sending puback
<<<output continues until normal termination>>>
版本：
boto3==1.17.96
awscrt==0.11.22
awsiotsdk==1.6.0
我使用以下方法创建了我的 mqtt 连接：
mqtt_connection_builder.websockets_with_default_aws_signing(
endpoint='#############-ats.iot.us-west-2.amazonaws.com',
client_bootstrap=client_bootstrap,
region=AWS_REGION,
credentials_provider=credentials_provider,
ca_filepath=f'{self.certs_temp_dir.name}/AmazonRootCA1.pem',
on_connection_interrupted=self._on_connection_interrupted,
on_connection_resumed=self._on_connection_resumed,
client_id=f'test-{uuid.uuid4()}',
clean_session=False,
keep_alive_secs=6
)
我这里没有足够的信息来确定问题所在。但是，我担心的是 unittest 导致了意外行为。这是一个相当复杂的集成测试，你可能没有正确或及时地释放资源，这导致AWS不高兴。
我担心的最明显的罪魁祸首是每次测试都具有相同的 client_id。我会尝试为每个测试随机化。
我正在相当接近 awsiotsdk 包中的 pub/sub example。我的基本单元测试有时成功有时失败。
我使用 awscrt.io.init_logging(6, 'stderr')
当我查看跟踪日志时，它们看起来相对类似于这一行：
[TRACE] [2021-06-16T23:56:36Z] [00007f5fcfbbc640] [mqtt-topic-tree] - tree=0x5565ac073898: Publishing on topic test/unittest
在那之后，失败的 运行 开始循环生成以下输出，直到我的单元测试在 30 秒后超时：
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolving host #############-ats.iot.us-west-2.amazonaws.com
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 34.213.168.191
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 52.35.137.184
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 54.148.88.142
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 34.214.249.117
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 54.186.43.162
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 52.38.221.226
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 54.244.33.231
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 34.218.88.107
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::23a6:36ae
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::3424:419e
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::22d2:b01f
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::22d7:fa17
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::6415:4c4c
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::2351:30a6
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::3421:1d4e
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: resolved record: 2620:108:700f::342b:929
[DEBUG] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static, resolving host #############-ats.iot.us-west-2.amazonaws.com successful, returned 16 addresses
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 34.213.168.191 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 52.35.137.184 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 54.148.88.142 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 34.214.249.117 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 54.186.43.162 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 52.38.221.226 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 54.244.33.231 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 34.218.88.107 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::23a6:36ae for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::3424:419e for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::22d2:b01f for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::22d7:fa17 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::6415:4c4c for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::2351:30a6 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::3421:1d4e for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: updating expiry for 2620:108:700f::342b:929 for host #############-ats.iot.us-west-2.amazonaws.com to 1623887576445112777
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: remaining record count for host 7
[TRACE] [2021-06-16T23:52:26Z] [00007fd7ab15b640] [dns] - static: remaining record count for host 8
A 运行 成功从 Publishing on topic test/unittest 消息继续：
[TRACE] [2021-06-16T23:56:36Z] [00007f5fcfbbc640] [mqtt-client] - id=0x5565ac073640: publish received with msg id=1 dup=0 qos=1 retain=0 payload-size=16 topic=test/unittest
[TRACE] [2021-06-16T23:56:36Z] [00007f5fcfbbc640] [mqtt-client] - id=0x5565ac073640: received publish QOS is 1, sending puback
<<<output continues until normal termination>>>
版本：
boto3==1.17.96
awscrt==0.11.22
awsiotsdk==1.6.0
我使用以下方法创建了我的 mqtt 连接：
mqtt_connection_builder.websockets_with_default_aws_signing(
endpoint='#############-ats.iot.us-west-2.amazonaws.com',
client_bootstrap=client_bootstrap,
region=AWS_REGION,
credentials_provider=credentials_provider,
ca_filepath=f'{self.certs_temp_dir.name}/AmazonRootCA1.pem',
on_connection_interrupted=self._on_connection_interrupted,
on_connection_resumed=self._on_connection_resumed,
client_id=f'test-{uuid.uuid4()}',
clean_session=False,
keep_alive_secs=6
)
我这里没有足够的信息来确定问题所在。但是，我担心的是 unittest 导致了意外行为。这是一个相当复杂的集成测试，你可能没有正确或及时地释放资源，这导致AWS不高兴。
我担心的最明显的罪魁祸首是每次测试都具有相同的 client_id。我会尝试为每个测试随机化。