Skip to content

[BUG] "Pausing CURL read for upload handle x" without new upload handle ready #452

Open
@bachtran02

Description

@bachtran02

Media pipeline:

  • Media source: getFrame() from camera SDK which continuously returns h264 frames are then passed to putKinesisVideoFrame(), I-type frames marked as FRAME_FLAG_KEY_FRAME
  • Media type: video, no audio
  • Codec information: h264 frames
  • Intermittent/continuous streaming: continuous streaming

Logging

2024-07-30T05:32:30.639-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:55.207 INFO    getStreamData(): [store-1-cam-2] Indicating an EOS after last persisted ACK is received for stream upload handle 39
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     Authorization: AWS4-HMAC-SHA256 Credential=ABCDE/12345/us-west-2/kinesisvideo/aws4_request, SignedHeaders=connection;host;transfer-encoding;user-agent;x-amz-date;x-amzn-fragment-acknowledgment-required;x-amzn-fragment-timecode-type;x-amzn-producer-start-timestamp;x-amzn-stream-name, Signature=abcde
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     connection: keep-alive
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     content-type: application/json
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     host: a-abcde.kinesisvideo.us-west-2.amazonaws.com
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     transfer-encoding: chunked
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:55.207 INFO    postReadCallback(): Reported end-of-stream for stream store-1-cam-2. Upload handle: 39
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:56.581 WARN    curlCompleteSync(): [store-1-cam-2] HTTP Error 0 : Response: (null)
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:56.581 WARN    curlCompleteSync(): [store-1-cam-2] curl perform failed for url https://a-abcde.kinesisvideo.us-west-2.amazonaws.com/putMedia with result Timeout was reached: Connection time-out
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: Request Headers:
2024-07-30T05:32:30.640-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: Request URL: https://a-abcde.kinesisvideo.us-west-2.amazonaws.com/putMedia
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     X-Amz-Date: 20240730T114251Z
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     user-agent: AWS-PRODUCER-SDK-KVS/1.5.2 GCC/11.2.0 Linux/4.14.255-axis8 aarch64
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     x-amz-security-token: abcde
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     x-amzn-fragment-acknowledgment-required: 1
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     x-amzn-fragment-timecode-type: ABSOLUTE
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     x-amzn-producer-start-timestamp: 1722339771.566
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]:     x-amzn-stream-name: store-1-cam-2
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:56.581 INFO    kinesisVideoStreamTerminated(): Stream 0x55b76e4930 terminated upload handle 40 with service call result 599.
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:56.581 INFO    putStreamResultEvent(): Put stream result event. New upload handle 41
2024-07-30T05:32:30.643-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:56.581 WARN    putStreamCurlHandler(): [store-1-cam-2] Stream with streamHandle 368149678384 uploadHandle 40 has exited without triggering end-of-stream. Service call result: 599
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:42:56.591 WARN    notifyDataAvailable(): [store-1-cam-2] Failed to un-pause curl with error: 43. Curl object 0x55b77cdb50
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 11:43:04.194 INFO    writeHeaderCallback(): RequestId: e378c362-0058-7130-bc5a-177e2b9959c3
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:48.603 INFO    getStreamingEndpointResultEvent(): Get streaming endpoint result event.
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:48.603 INFO    getStreamingTokenResultEvent(): Get streaming token result event.
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:48.604 INFO    putStreamResultEvent(): Put stream result event. New upload handle 42
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:48.772 INFO    writeHeaderCallback(): RequestId: dd0097b6-2c10-0edd-8222-4b0f65073c0a
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:52.077 INFO    getStreamData(): [store-1-cam-2] Handle 41 waiting for last persisted ack with ts 17223413967340000
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:52.307 INFO    getStreamData(): [store-1-cam-2] Indicating an EOS after last persisted ACK is received for stream upload handle 41
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:19:52.307 INFO    postReadCallback(): Reported end-of-stream for stream store-1-cam-2. Upload handle: 41
2024-07-30T05:32:30.646-07:00 axis-b8a44f677c6d [ INFO    ] KvsAxisStreaming[25813]: 2024-07-30 12:32:30.633 INFO    writeHeaderCallback(): RequestId: e4f14ab1-8918-456e-8877-ab5a7ccaaf72
2024-07-30T05:33:44.580-07:00 axis-b8a44f677c6d [ ERR     ] KvsAxisStreaming[25813]: Kinesis Producer SDK failed: status=0x16000001

Describe the bug
The bug occurred roughly 12 hours after the app started. Everything was working fine before. There was a few curl issues (status=0x16000001) here and there but were not breaking errors. This one breaks the application.

SDK version number
v1.5.2

Screenshot
image

To Reproduce
N/A

Expected behavior
The bug to not occur and the stream continues to work.

Desktop (please complete the following information):

  • OS: Axis OS (camera OS)
  • Architecture: aarch64
  • Browser N/A
  • Version N/A

Additional context
The app runs on Axis camera and streams to AWS Kinesis
Code Summary:

  • create Kinesis client default callback with IoT certificates
  • create Kinesis stream callback
  • add stream callback to client callback (only 1 stream on this client)
  • create Kinesis video client
  • create Kinesis video stream sync
  • create vdostream which is responsible for accessing h264 frames from camera livestream
  • create loop that continuously fetches h264 frames from vdostream, construct Kinesis Frame with the data and send to putKinesisVideoFrame()

OpenSSL and Curl are both cross-compiled for aarch64.

  • curl version: 8.8.0
  • openssl version: 3.0.0

Metadata

Metadata

Assignees

No one assigned

    Labels

    awaiting-responseAwaiting for customers responsebugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions