tanhakabir / SwiftAudioPlayer

Streaming and realtime audio manipulation with AVAudioEngine
https://medium.com/chameleon-podcast/creating-an-advanced-streaming-audio-engine-for-ios-9fbc7aef4115
MIT License
566 stars 109 forks source link

Streaming/Subsonic server issue #20

Closed fizzyade closed 4 years ago

fizzyade commented 4 years ago

Trying to get this library to work with a subsonic server, I see the server transcoding and serving the audio, but the player only ever gets into the buffering state, no playback actuall occurs.

Any ideas?

fizzyade commented 4 years ago

Here's with logging set to debug

The lines:

2019-12-16 11:31:17.551256+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.551523+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]

Just carry on outputting ad-infitium.

2019-12-16 11:31:16.105285+0000 streamingapp[23660:509050] [plugin] AddInstanceForFactory: No factory registered for id <CFUUID 0x60000061e840> F8BB1C28-BAE8-11D6-9C31-00039315CD46
2019-12-16 11:31:16.352828+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioStreamEngine.swift:init(withRemoteUrl:delegate:):137:: <redacted>
2019-12-16 11:31:17.262566+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioDownloadWorker.swift:init(allowCellular:progressCallback:doneCallback:backgroundDownloadCallback:):75:: init with allowCellular: false
2019-12-16 11:31:17.276559+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] FileStorage.swift:read(_:):98:: [Optional("Trying to get data for audio file that doesn\'t exist: audio_2919782377466288492")]
2019-12-16 11:31:17.277360+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioDownloadWorker.swift:stop(withID:callback:):140:: paramId: audio_2919782377466288492, activeDownloadIDs:
2019-12-16 11:31:17.277948+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioDownloadWorker.swift:pauseAllActive():124:: activeDownloadIDs:
2019-12-16 11:31:17.278375+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioStreamWorker.swift:start(withID:withRemoteURL:withInitialData:andTotalBytesExpectedPreviously:):99:: selfID: none, paramID: audio_2919782377466288492 initialData: 0
2019-12-16 11:31:17.433578+0000 streamingapp[23660:509346] [DEBUG 🐝🐝🐝🐝] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:completionHandler:):263:: [Optional("audio_2919782377466288492"), Optional("audio_2919782377466288492"), Optional("<NSHTTPURLResponse: 0x600000638d00> { URL: <redacted> } { Status Code: 200, Headers {\n    \"Access-Control-Allow-Origin\" =     (\n        \"*\"\n    );\n    \"Content-Type\" =     (\n        \"audio/mp4\"\n    );\n    Date =     (\n        \"Mon, 16 Dec 2019 11:31:17 GMT\"\n    );\n    Etag =     (\n        598\n    );\n    Server =     (\n        Caddy\n    );\n    \"Set-Cookie\" =     (\n        \"player-7361726168=9; Max-Age=31536000; Expires=Tue, 15-Dec-2020 11:31:17 GMT; Path=/\"\n    );\n    \"Strict-Transport-Security\" =     (\n        \"max-age=15552000;\"\n    );\n    \"x-content-duration\" =     (\n        \"338.0\"\n    );\n} }")]
2019-12-16 11:31:17.433915+0000 streamingapp[23660:509346] [INFO  🖤🖤🖤🖤] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:completionHandler:):274:: response length: -1
2019-12-16 11:31:17.435013+0000 streamingapp[23660:509346] [DEBUG 🐝🐝🐝🐝] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:):238:: [Optional("selfID: "), Optional("audio_2919782377466288492"), Optional(" dataTaskID: "), Optional("audio_2919782377466288492"), Optional(" dataSize: "), Optional(5921), Optional(" expected: "), Optional(-1), Optional(" received: "), Optional(0)]
2019-12-16 11:31:17.435206+0000 streamingapp[23660:509346] [MONITOR 🔥🔥🔥🔥] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:):251:: should not be called 223r2
2019-12-16 11:31:17.436001+0000 streamingapp[23660:509346] [DEBUG 🐝🐝🐝🐝] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:):238:: [Optional("selfID: "), Optional("audio_2919782377466288492"), Optional(" dataTaskID: "), Optional("audio_2919782377466288492"), Optional(" dataSize: "), Optional(57454), Optional(" expected: "), Optional(-1), Optional(" received: "), Optional(0)]
2019-12-16 11:31:17.436184+0000 streamingapp[23660:509346] [MONITOR 🔥🔥🔥🔥] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:):251:: should not be called 223r2
2019-12-16 11:31:17.474540+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.475645+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.476570+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.476926+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioStreamEngine.swift:updateNeedle():240:: reached end of audio
2019-12-16 11:31:17.477087+0000 streamingapp[23660:509050] [INFO  🖤🖤🖤🖤] AudioStreamEngine.swift:seek(toNeedle:):257:: didSeek to needle: 0.0
2019-12-16 11:31:17.477250+0000 streamingapp[23660:509050] [ERROR 🛑🛑🛑🛑] AudioStreamEngine.swift:seek(toNeedle:):262:: tried to seek beyond duration
2019-12-16 11:31:17.491015+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.491288+0000 streamingapp[23660:509347] [DEBUG 🐝🐝🐝🐝] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:):238:: [Optional("selfID: "), Optional("audio_2919782377466288492"), Optional(" dataTaskID: "), Optional("audio_2919782377466288492"), Optional(" dataSize: "), Optional(198769), Optional(" expected: "), Optional(-1), Optional(" received: "), Optional(0)]
2019-12-16 11:31:17.491367+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.491507+0000 streamingapp[23660:509347] [MONITOR 🔥🔥🔥🔥] AudioStreamWorker.swift:urlSession(_:dataTask:didReceive:):251:: should not be called 223r2
2019-12-16 11:31:17.491601+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.495227+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.495492+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.495743+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.499029+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.499333+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.499584+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.504778+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.505130+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.505410+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.511121+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.511417+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.511661+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.516407+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.516730+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.517008+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.522521+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.522832+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.523082+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.528120+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.528492+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.528784+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.546065+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.546374+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
2019-12-16 11:31:17.546616+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:updateNetworkBufferRange():220:: [Optional("loaded (0.0, 0.0), numberOfBuffersScheduledInTotal: 0, isPlayable: false")]
2019-12-16 11:31:17.551256+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioConverter.swift:pullBuffer(withSize:):113:: [Optional("reader_error trying to read before converter has been created")]
2019-12-16 11:31:17.551523+0000 streamingapp[23660:509050] [DEBUG 🐝🐝🐝🐝] AudioStreamEngine.swift:pollForNextBuffer():187:: [Optional("Could not create a PCM Buffer because reader does not have a converter yet")]
fizzyade commented 4 years ago

Ok, the problem lies here:

    func urlSession(_ session: URLSession, dataTask: URLSessionDataTask, didReceive response: URLResponse, completionHandler: @escaping (URLSession.ResponseDisposition) -> Void) {
        Log.debug(dataTask.taskDescription, id, response.description)
        guard id != nil else {
            Log.monitor("stream worker in weird state 2049jg3")
            return
        }

        guard self.task == dataTask else {
            Log.error("stream_error not the same task")
            return
        }

        Log.info("response length: \(response.expectedContentLength)")

        //the value will smaller if you seek. But we want to hold the OG total for duration calculations
        if !corruptedBecauseOfSeek {
            totalBytesExpectedForWholeFile = response.expectedContentLength + initialDataBytesCount
        }

        **totalBytesExpectedForCurrentStream = response.expectedContentLength**

        completionHandler(.allow)
    }

Subsonic is not sending a content length because it is transcoding the audio and therefore doesn't know how big the file is going to be, a quick test of fudging in a number there results in audio being played.

Without fudging in a number, the totalBytesExpectedForCurrentStream variable is set to -1 which breaks playback.

tanhakabir commented 4 years ago

I want to repro this, what URL did you use?

fizzyade commented 4 years ago

I want to repro this, what URL did you use?

It's my own server, I can generate you a link to a file but I can't post it publicly, where should I send the link to?

tanhakabir commented 4 years ago

Ah I see, thanks! Feel free to email it to me: tanhakabir.ca@gmail.com