aws / aws-iot-device-sdk-embedded-C

SDK for connecting to AWS IoT from a device using embedded C.
MIT License
974 stars 622 forks source link

Jobs debug #1906

Closed yanyunfanblill closed 3 months ago

yanyunfanblill commented 3 months ago

I want to update the results of the jobs process, now the status is IN_PROGRESS, I want change it to SUCCEEDED. Is there any problem with the below publish parameter? No publish ack has been received publish topic: aws/things/Demo_oa8100/jobs/testJobs/update publish payload: {"status":"SUCCEEDED"}

tony-josi-aws commented 3 months ago

@yanyunfanblill

UpdateJobExecution documentation specifies that:

The message broker will publish $aws/things/thingName/jobs/jobId/update/accepted and $aws/things/thingName/jobs/jobId/update/rejected even without a specific subscription to them. However, for your client to receive the messages, it must be listening for them.

Is your client listening to these topics?

yanyunfanblill commented 3 months ago

I subscript to $aws/things/Demo_oa8100/jobs/+/update/accepted and $aws/things/Demo_oa8100/jobs/+/update/rejected I notice the update payload format as follows, Should I list all of them? { "status": "job-execution-state", "statusDetails": { "string": "string" ... }, "expectedVersion": "number", "executionNumber": long, "includeJobExecutionState": boolean, "includeJobDocument": boolean, "stepTimeoutInMinutes": long, "clientToken": "string" }

tony-josi-aws commented 3 months ago

@yanyunfanblill

status and expectedVersion should be the minimal fields required. Is the expectedVersion field following the required conditions in the docs?:

If the version of the job execution stored in the AWS IoT Jobs service doesn't match, the update is rejected with a VersionMismatch error. An ErrorResponse that contains the current job execution status data is also returned.

yanyunfanblill commented 3 months ago

$aws/things/Demo_oa8100/jobs/testJobs/update/rejected seems have below message, Invalid Json payload? { "timestamp":1711954423, "code":"InvalidJson", "message":"Unexpected end-of-input in field name at [Source: (iot.laser.tjm.handler.utils.DeviceMessageParser$1); line: 1, column: 5]" }@

tony-josi-aws commented 3 months ago

Is the message sent to the broker following right JSON syntax? Are you escaping the quotes correctly inside the string? For example:

#define MAKE_STATUS_REPORT( x ) "{\"status\":\"" x "\"}"

yanyunfanblill commented 3 months ago

I use snprintf to generate payload, any problem?

#define REPORT_SUCCESS                  \
"{"                                                      \
"\"status\":\"SUCCEEDED\","               \
"\"expectedVersion\": %01d "              \
"}"
snprintf( updateDoc, REPORTED_SUCCESS_LEN, REPORT_SUCCESS,( int ) ver_num);

log:

[INFO] [JOBS] [jobs_demo_main.c:704] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion": 2 }
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 12.
[INFO] [JOBS] [jobs_demo_main.c:704] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion": 2 }
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 13.
[INFO] [JOBS] [jobs_demo_main.c:704] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion": 2 }
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 14.
[INFO] [JOBS] [jobs_demo_main.c:704] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion": 2 }
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 15.
[INFO] [JOBS] [jobs_demo_main.c:704] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion": 2 }
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 16.
[INFO] [JOBS] [jobs_demo_main.c:704] Receive snapshot command!
[ERROR] [JOBS_DEMO] [jobs_demo_helpers.c:1156] Unable to find a free spot for outgoing PUBLISH message.
[ERROR] [JOBS] [jobs_demo_main.c:638] Failed to update jobs status.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 12.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 12.
[INFO] [JOBS] [jobs_demo_main.c:779] update failure for unknown job id: testJobs
[INFO] [JOBS] [jobs_demo_main.c:780] payload: $aws/things/Demo_oa8100/jobs/testJobs/update/rejected{"timestamp":1711960300,"code":"InvalidJson","message":"Unexpected end-of-input in field name at [Source: (iot.laser.tjm.handler.utils.DeviceMessageParser$1); line: 1, column: 5]"}@ 9
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 13.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 13.
[INFO] [JOBS] [jobs_demo_main.c:779] update failure for unknown job id: testJobs
[INFO] [JOBS] [jobs_demo_main.c:780] payload: $aws/things/Demo_oa8100/jobs/testJobs/update/rejected{"timestamp":1711960300,"code":"InvalidJson","message":"Unexpected end-of-input in field name at [Source: (iot.laser.tjm.handler.utils.DeviceMessageParser$1); line: 1, column: 5]"}@ 9
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 14.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 14.
tony-josi-aws commented 3 months ago

I believe the value of the field expectedVersion is supposed to be a string in quotes.

Refer: UpdateJobExecution

yanyunfanblill commented 3 months ago

ok, thanks, I notice the problem, now the aws jobs can show success job. there is another problem, first I publish to topic start-next, and then publish to topic update in JobsStartNextSuccess call back, I only publish once but it publish until unable to find a free package ID. Anything wrong with my flow?

log:

[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload:
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/start-next to broker with packet ID 11.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 11.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 11.
[INFO] [JOBS] [jobs_demo_main.c:705] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion":"2"}
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 12.
[INFO] [JOBS] [jobs_demo_main.c:705] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion":"2"}
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 13.
[INFO] [JOBS] [jobs_demo_main.c:705] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion":"2"}
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 14.
[INFO] [JOBS] [jobs_demo_main.c:705] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion":"2"}
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 15.
[INFO] [JOBS] [jobs_demo_main.c:705] Receive snapshot command!
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1160] Published payload: {"status":"SUCCEEDED","expectedVersion":"2"}
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:1185] PUBLISH sent for topic $aws/things/Demo_oa8100/jobs/testJobs/update to broker with packet ID 16.
[INFO] [JOBS] [jobs_demo_main.c:705] Receive snapshot command!
[ERROR] [JOBS_DEMO] [jobs_demo_helpers.c:1156] Unable to find a free spot for outgoing PUBLISH message.
payload: $aws/things/Demo_oa8100/jobs/testJobs/update testJobs 8 44 {"status":"SUCCEEDED","expectedVersion":"2"} 44
[ERROR] [JOBS] [jobs_demo_main.c:639] Failed to update jobs status.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 12.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 12.
[INFO] [JOBS] [jobs_demo_main.c:784] job update success
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 13.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 13.
[INFO] [JOBS] [jobs_demo_main.c:780] update failure for unknown job id: testJobs
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:748] PUBACK received for packet id 14.
[INFO] [JOBS_DEMO] [jobs_demo_helpers.c:635] Cleaned up outgoing publish packet with packet id 14.
[INFO] [JOBS] [jobs_demo_main.c:780] update failure for unknown job id: testJobs
tony-josi-aws commented 3 months ago

Thanks for reporting back.

The flow from the logs seems fine; probably you can set a break point and examine what's triggering the repeated PUBLISH.

yanyunfanblill commented 3 months ago

It seems JobsStartNextSuccess callback function invoked many times, is it possible that website will keep sending start-next success?

yanyunfanblill commented 3 months ago

I found if I put update publish in JobsStartNextSuccess callback, it will cause the problem mentioned. so I use a flag, and publish in main function, it works well, thx for your support.

tony-josi-aws commented 3 months ago

Thanks for reporting back, that explains the chaining of JobsStartNextSuccess.