shogo4405 / HaishinKit.swift

Camera and Microphone streaming library via RTMP and SRT for iOS, macOS, tvOS and visionOS.
BSD 3-Clause "New" or "Revised" License
2.76k stars 612 forks source link

Sometimes stream remains open when invalid stream key is used #1072

Closed charmingtoad closed 1 year ago

charmingtoad commented 2 years ago

Describe the bug

If a user enters the wrong stream key, I want to let them know that their stream failed to start.

I'm currently listening to stream events with

let connection = RTMPConnection()
connection.addEventListener(.rtmpStatus, selector: #selector(rtmpStatusHandler), observer: self)

Usually if a user enters a bad stream key, rtmpStatusHandler is immediately called with NetConnection.Connect.Closed.

However, sometimes it takes 30 or more seconds for the error to arrive. During this time I am not sure how to detect that the stream is not working. Is there a way? Thanks in advance.

To Reproduce

This can be reproduced in the Haishinkit iOS sample app.

  1. In LiveViewController.swift rtmpStatusHandler I added a couple logs that would be easy to filter by like so:
private func rtmpStatusHandler(_ notification: Notification) {
        let e = Event.from(notification)
        guard let data: ASObject = e.data as? ASObject, let code: String = data["code"] as? String else {
            return
        }
        print("xx code = \(code)")
        logger.info(code)
        switch code {
        case RTMPConnection.Code.connectSuccess.rawValue:
            retryCount = 0
            rtmpStream!.publish(Preference.defaultInstance.streamName!)
            // sharedObject!.connect(rtmpConnection)
        case RTMPConnection.Code.connectFailed.rawValue, RTMPConnection.Code.connectClosed.rawValue:
            guard retryCount <= LiveViewController.maxRetryCount else {
                return
            }
            Thread.sleep(forTimeInterval: pow(2.0, Double(retryCount)))
            print("xx attempting reconnect")
            rtmpConnection.connect(Preference.defaultInstance.uri!)
            retryCount += 1
        default:
            break
        }
    }
  1. Run the app
  2. Tap the bottom right Preference tab
  3. For stream url, enter rtmp://lax.contribute.live-video.net/app/
  4. Enter a bad stream key like abc
  5. Tap Open Window
  6. Tap the circular stream button
  7. Filter logs in Xcode so only the 'xx' logs show up

Result:

You'll see a cycle like this

xx code = NetConnection.Connect.Success
xx code = NetStream.Publish.Start
xx code = NetConnection.Connect.Closed
xx attempting reconnect

But eventually it hangs like this

xx attempting reconnect
xx code = NetConnection.Connect.Success
xx code = NetStream.Publish.Start

At this point I am not sure how to detect that the stream is failing to start.

Expected behavior

xx code = NetConnection.Connect.Closed should log pretty quickly after each xx code = NetStream.Publish.Start

Version

1.1.5

Smartphone info.

iPhone 14 Pro iOS 16.0.1 (20A371)

Additional context

For log output below, I turned on Logboard.with(HaishinKitIdentifier).level = .trace and included logs from the time I tapped stream with an invalid stream key. The last logs repeat infinitely. The NetConnection.Connect.Closed event didn't come in.

Screenshots

No response

Relevant log output

2022-28-09 17:57:17.301 [Debug] [com.haishinkit.HaishinKit] [RTMPConnection.swift:464] didSetReadyState(_:) > uninitialized
2022-28-09 17:57:17.505 [Debug] [com.haishinkit.HaishinKit] [RTMPConnection.swift:464] didSetReadyState(_:) > versionSent
2022-28-09 17:57:17.536 [Debug] [com.haishinkit.HaishinKit] [RTMPConnection.swift:464] didSetReadyState(_:) > ackSent
2022-28-09 17:57:17.539 [Debug] [com.haishinkit.HaishinKit] [RTMPConnection.swift:464] didSetReadyState(_:) > handshakeDone
2022-28-09 17:57:17.541 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 284,streamId: 0,timestamp: 0,payload: 272 bytes,objectEncoding: amf0,commandName: connect,transactionId: 1,commandObject: Optional(["videoCodecs": Optional(128), "pageUrl": nil, "flashVer": Optional("FMLE/3.0 (compatible; FMSc/1.0)"), "videoFunction": Optional(1), "audioCodecs": Optional(1024), "swfUrl": nil, "app": Optional("app"), "fpad": Optional(false), "capabilities": Optional(239), "objectEncoding": Optional(0), "tcUrl": Optional("rtmp://lax.contribute.live-video.net/app/")]),arguments: [],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.567 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 128,type: zero,streamId: 2,message: Optional(RTMPWindowAcknowledgementSizeMessage{type: windowAck,length: 4,streamId: 0,timestamp: 0,payload: 4 bytes,size: 2500000}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.568 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 2,message: Optional(RTMPWindowAcknowledgementSizeMessage{type: windowAck,length: 16,streamId: 0,timestamp: 0,payload: 4 bytes,size: 2500000}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.569 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 128,type: zero,streamId: 2,message: Optional(RTMPSetPeerBandwidthMessage{type: bandwidth,length: 5,streamId: 0,timestamp: 0,payload: 5 bytes,size: 2500000,limit: dynamic}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.570 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 128,type: zero,streamId: 2,message: Optional(RTMPUserControlMessage{type: user,length: 6,streamId: 0,timestamp: 0,payload: 6 bytes,event: streamBegin,value: 0}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.571 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 128,type: zero,streamId: 2,message: Optional(RTMPSetChunkSizeMessage{type: chunkSize,length: 4,streamId: 0,timestamp: 0,payload: 4 bytes,size: 4096}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.572 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 4096,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 236,streamId: 0,timestamp: 0,payload: 236 bytes,objectEncoding: amf0,commandName: _result,transactionId: 1,commandObject: Optional(["fmsVer": Optional("FMS/3,5,7,7009"), "capabilities": Optional(31.0), "mode": Optional(1.0)]),arguments: [Optional(["level": Optional("status"), "code": Optional("NetConnection.Connect.Success"), "objectEncoding": Optional(0.0), "data": Optional(["string": Optional("3,5,7,7009")]), "description": Optional("Connection accepted.")])],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.573 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 2,message: Optional(RTMPSetChunkSizeMessage{type: chunkSize,length: 16,streamId: 0,timestamp: 0,payload: 4 bytes,size: 8192}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.573 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 37,streamId: 0,timestamp: 0,payload: 25 bytes,objectEncoding: amf0,commandName: createStream,transactionId: 2,commandObject: nil,arguments: [],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
xx code = NetConnection.Connect.Success
2022-28-09 17:57:17.573 [Info] [com.haishinkit.Exsample.iOS] [LiveViewController.swift:156] rtmpStatusHandler(_:) > NetConnection.Connect.Success
2022-28-09 17:57:17.601 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 4096,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 29,streamId: 0,timestamp: 0,payload: 29 bytes,objectEncoding: amf0,commandName: _result,transactionId: 2,commandObject: Optional([:]),arguments: [Optional(1.0)],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.603 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 40,streamId: 0,timestamp: 0,payload: 28 bytes,objectEncoding: amf0,commandName: FCPublish,transactionId: 4,commandObject: nil,arguments: [Optional("abc")],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.604 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 45,streamId: 1,timestamp: 0,payload: 33 bytes,objectEncoding: amf0,commandName: publish,transactionId: 3,commandObject: nil,arguments: [Optional("abc"), Optional("live")],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.604 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 4096,type: zero,streamId: 2,message: Optional(RTMPUserControlMessage{type: user,length: 6,streamId: 0,timestamp: 0,payload: 6 bytes,event: streamBegin,value: 1}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.619 [Trace] [com.haishinkit.HaishinKit] [RTMPConnection.swift:523] listen(_:) > RTMPChunk{size: 4096,type: zero,streamId: 3,message: Optional(RTMPCommandMessage{type: amf0Command,length: 115,streamId: 0,timestamp: 0,payload: 115 bytes,objectEncoding: amf0,commandName: onFCPublish,transactionId: 0,commandObject: Optional([:]),arguments: [Optional(["description": Optional("FCPublish to stream abc"), "level": Optional("status"), "code": Optional("NetStream.Publish.Start")])],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
xx code = NetStream.Publish.Start
2022-28-09 17:57:17.620 [Info] [com.haishinkit.Exsample.iOS] [LiveViewController.swift:156] rtmpStatusHandler(_:) > NetStream.Publish.Start
2022-28-09 17:57:17.620 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 3,message: Optional(RTMPDataMessage{type: amf0Data,length: 192,streamId: 1,timestamp: 0,payload: 180 bytes,objectEncoding: amf0,handlerName: @setDataFrame,arguments: [Optional("onMetaData"), Optional(["videocodecid": Optional(7), "audiodatarate": Optional(32), "width": Optional(720), "height": Optional(1280), "audiocodecid": Optional(10), "videodatarate": Optional(160), "framerate": Optional(30.0)])],serializer: AMF0Serializer{data: 0 bytes,position: 0,reference: HaishinKit.AMFReference}}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.630 [Info] [com.haishinkit.HaishinKit] [AudioCodec.swift:94] inSourceFormat > AudioStreamBasicDescription(mSampleRate: 48000.0, mFormatID: 1819304813, mFormatFlags: 12, mBytesPerPacket: 2, mFramesPerPacket: 1, mBytesPerFrame: 2, mChannelsPerFrame: 1, mBitsPerChannel: 16, mReserved: 0)
2022-28-09 17:57:17.632 [Info] [com.haishinkit.HaishinKit] [AudioCodec.swift:81] formatDescription > Optional(<CMAudioFormatDescription 0x280ef4500 [0x21a4ee3a0]> {
    mediaType:'soun' 
    mediaSubType:'aac ' 
    mediaSpecific: {
        ASBD: {
            mSampleRate: 48000.000000 
            mFormatID: 'aac ' 
            mFormatFlags: 0x2 
            mBytesPerPacket: 0 
            mFramesPerPacket: 1024 
            mBytesPerFrame: 0 
            mChannelsPerFrame: 1 
            mBitsPerChannel: 0  } 
        cookie: {(null)} 
        ACL: {(null)}
        FormatList Array: {
            Index: 0 
            ChannelLayoutTag: 0x640001 
            ASBD: {
            mSampleRate: 48000.000000 
            mFormatID: 'aac ' 
            mFormatFlags: 0x2 
            mBytesPerPacket: 0 
            mFramesPerPacket: 1024 
            mBytesPerFrame: 0 
            mChannelsPerFrame: 1 
            mBitsPerChannel: 0  }} 
    } 
    extensions: {(null)}
})
2022-28-09 17:57:17.633 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 8,message: Optional(RTMPAudioMessage{type: audio,length: 16,streamId: 1,timestamp: 0,payload: 4 bytes,codec: unknown,soundRate: kHz44,soundSize: snd8bit,soundType: stereo}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.639 [Info] [com.haishinkit.HaishinKit] [AudioCodec.swift:72] actualBitrate > 32000
2022-09-28 17:57:17.638690-0700 Example iOS[36728:2992087] [AudioConverter] CompositeAudioConverter.cpp:1239  Input data proc returned inconsistent 1 packets for 2048 bytes; at 2 bytes per packet, that is actually 1024 packets
2022-09-28 17:57:17.649557-0700 Example iOS[36728:2992087] [AudioConverter] CompositeAudioConverter.cpp:1239  Input data proc returned inconsistent 1 packets for 2048 bytes; at 2 bytes per packet, that is actually 1024 packets
2022-28-09 17:57:17.650 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: one,streamId: 8,message: Optional(RTMPAudioMessage{type: audio,length: 14,streamId: 1,timestamp: 0,payload: 6 bytes,codec: unknown,soundRate: kHz44,soundSize: snd8bit,soundType: stereo}),fragmented: false,_data: 8 bytes}
2022-09-28 17:57:17.670670-0700 Example iOS[36728:2992426] [AudioConverter] CompositeAudioConverter.cpp:1239  Input data proc returned inconsistent 1 packets for 2048 bytes; at 2 bytes per packet, that is actually 1024 packets
2022-28-09 17:57:17.671 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: one,streamId: 8,message: Optional(RTMPAudioMessage{type: audio,length: 115,streamId: 1,timestamp: 0,payload: 107 bytes,codec: unknown,soundRate: kHz44,soundSize: snd8bit,soundType: stereo}),fragmented: false,_data: 8 bytes}
2022-09-28 17:57:17.692689-0700 Example iOS[36728:2992426] [AudioConverter] CompositeAudioConverter.cpp:1239  Input data proc returned inconsistent 1 packets for 2048 bytes; at 2 bytes per packet, that is actually 1024 packets
2022-28-09 17:57:17.693 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: one,streamId: 8,message: Optional(RTMPAudioMessage{type: audio,length: 111,streamId: 1,timestamp: 21,payload: 103 bytes,codec: unknown,soundRate: kHz44,soundSize: snd8bit,soundType: stereo}),fragmented: false,_data: 8 bytes}
2022-28-09 17:57:17.693 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: zero,streamId: 9,message: Optional(RTMPVideoMessage{type: video,length: 42,streamId: 1,timestamp: 0,payload: 30 bytes,codec: unknown,status: 0}),fragmented: false,_data: 12 bytes}
2022-28-09 17:57:17.695 [Debug] [com.haishinkit.HaishinKit] [RTMPStream.swift:611] sampleOutput(video:withTimestamp:muxer:) > first video frame was sent
2022-28-09 17:57:17.695 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: one,streamId: 9,message: Optional(RTMPVideoMessage{type: video,length: 2913,streamId: 1,timestamp: 0,payload: 2905 bytes,codec: unknown,status: 0}),fragmented: false,_data: 8 bytes}
2022-28-09 17:57:17.699 [Trace] [com.haishinkit.HaishinKit] [RTMPSocket.swift:48] doOutput(chunk:locked:) > RTMPChunk{size: 0,type: one,streamId: 9,message: Optional(RTMPVideoMessage{type: video,length: 292,streamId: 1,timestamp: 0,payload: 284 bytes,codec: unknown,status: 0}),fragmented: false,_data: 8 bytes}
2022-09-28 17:57:17.714266-0700 Example iOS[36728:2992426] [AudioConverter] CompositeAudioConverter.cpp:1239  Input data proc returned inconsistent 1 packets for 2048 bytes; at 2 bytes per packet, that is actually 1024 packets
shogo4405 commented 1 year ago

Unfortunately, Client side can't detect invalid stream key in this case. And I have no idea. I hope, disconnected by live-video.net server or returns NetStream.Publish.Failed or NetStream.Publish.BadName.

charmingtoad commented 1 year ago

Got it. I wasn't sure if I might be doing something wrong. Sounds like it just depends on how the server responds. Thanks for looking!