Skip to content
This repository has been archived by the owner on Jan 16, 2024. It is now read-only.

Alexa SDK on Raspberry Pi - TuneIn stopped working - streamingError #1808

Closed
3 of 8 tasks
alexwala opened this issue Oct 15, 2020 · 2 comments
Closed
3 of 8 tasks

Alexa SDK on Raspberry Pi - TuneIn stopped working - streamingError #1808

alexwala opened this issue Oct 15, 2020 · 2 comments

Comments

@alexwala
Copy link

alexwala commented Oct 15, 2020 •
edited

IMPORTANT: Before you create an issue, please take a look at our Issue Reporting Guide.

Briefly summarize your issue:

Since couple of days tuneIn stopped working on Alexa SDK on raspberry pi.
On the other side amazon music works fine.
Getting HTTP_RESPONSE_CODE_UNDEFINED, MEDIA_ERROR_INTERNAL_DEVICE_ERROR, streamingError - see log.
Using Wireshark i get a valid m3u file containing radio station stream url.

What is the expected behavior?

Alexa SDK on raspberry pi should play tuneIn radio station.

What behavior are you observing?

After telling Alexa to play radio station , she is answering : 'playing radio station from tuneIn' but nothing happens.
From the log's, immediately after the answer, the status changes to 'Alexa is currently idle!':

#       Successfully registered 1 endpoint(s).
#       Authorized!
#       Alexa is currently idle!
-> alexa play radio station <x>
#       Listening...
#       Thinking...
#       Speaking...
<- playing radio station <x> from tuneIn
#       Alexa is currently idle!

Trying to play radio station using Alexa APP on raspberry pi device (does not work either):

2020-10-18 13:49:34.084 [ 29] 5 AudioPlayer:preHandleDirective:name=Play,messageId=ee6d86e1-281e-4d5d-bb78-a76f1dd62cec
2020-10-18 13:49:34.084 [ 15] 0 EventBuilder:buildJsonEventString:messageId=8dedd2db-4d02-47e9-8b4c-c1c293efd842,namespace=AudioPlayer,name=PlaybackQueueCleared
2020-10-18 13:49:34.084 [ 29] 1 AudioPlayer:preHandlePlayDirective
2020-10-18 13:49:34.084 [ 29] 9 AudioPlayer:prePLAY:payload={"audioItem"\:{"audioItemId"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#306863c6-83b1-4899-8f9c-31adfdd44b17\:1"\,"stream"\:{"offsetInMilliseconds"\:0\,"expiryTime"\:"2020-10-18T13\:50\:34+0000"\,"progressReport"\:{"progressReportIntervalInMilliseconds"\:900000}\,"interruptedBehavior"\:"ATTENUATE"\,"url"\:"http\://opml.radiotime.com/Tune.ashx?id\=e851049&sid\=s2614&formats\=aac\,mp3&partnerId\=4JqugguZ&serial\=AH4YFE6RM4NYPKLNXSHNBGLU3JGA"\,"token"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#306863c6-83b1-4899-8f9c-31adfdd44b17\:1"}}\,"playBehavior"\:"REPLACE_ALL"}
2020-10-18 13:49:34.084 [ 15] 0 EventBuilder:buildJsonEventString:event={"event"\:{"header"\:{"namespace"\:"AudioPlayer"\,"name"\:"PlaybackQueueCleared"\,"messageId"\:"8dedd2db-4d02-47e9-8b4c-c1c293efd842"}\,"payload"\:{}}}
2020-10-18 13:49:34.084 [ 29] 5 JsonUtils:findNode:reason=missingDirectChild,child=streamFormat
2020-10-18 13:49:34.084 [ 15] 7 HTTP2Transport:onRequestEnqueued:this=0xb52cd10
2020-10-18 13:49:34.084 [ 29] 5 JsonUtils:findNode:reason=missingDirectChild,child=endOffsetInMilliseconds
2020-10-18 13:49:34.084 [ 29] 5 JsonUtils:findNode:reason=missingDirectChild,child=progressReportDelayInMilliseconds
2020-10-18 13:49:34.084 [ 29] 5 JsonUtils:findNode:reason=missingDirectChild,child=expectedPreviousToken
2020-10-18 13:49:34.084 [ 29] 5 JsonUtils:findNode:reason=missingDirectChild,child=httpHeaders
2020-10-18 13:49:34.084 [ 1f] 7 MessageRequestHandler:create:context=0xb52cd78,messageRequest=0xe568190
2020-10-18 13:49:34.084 [ 29] 5 AudioPlayer:captionsNotParsed:reason=captionManagerIsNull
2020-10-18 13:49:34.084 [ 29] 5 JsonUtils:findNode:reason=missingDirectChild,child=playRequestor
2020-10-18 13:49:34.084 [ 1f] 5 ExchangeHandler:ExchangeHandler:context=0xb52cd78
2020-10-18 13:49:34.084 [ 15] 1 AudioPlayer:executePrePlay:messageId=ee6d86e1-281e-4d5d-bb78-a76f1dd62cec,preBufferBehavior=REPLACE_ALL
2020-10-18 13:49:34.084 [ 15] 0 AudioPlayer:executePrePlay::acquiringPlayerSetSource
2020-10-18 13:49:34.084 [ 1f] 7 MessageRequestHandler:MessageRequestHandler:context=0xb52cd78,messageRequest=0xe568190
2020-10-18 13:49:34.084 [ 1f] 9 HTTP2MimeRequestEncoder:HTTP2MimeRequestEncoder:boundary=WhooHooZeerOoonie!,source=0xe332958
2020-10-18 13:49:34.084 [ 1f] 9 MimeResponseSink:MimeResponseSink:handler=0xe332960
2020-10-18 13:49:34.084 [ 1f] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2020-10-18 13:49:34.084 [ 1f] 7 HTTP2Transport:onMessageRequestSent:this=0xb52cd10,countOfUnfinishedMessageHandlers=2
2020-10-18 13:49:34.084 [ 1f] 7 HTTP2Transport:createAndSendRequest:this=0xb52cd10,type=POST
2020-10-18 13:49:34.084 [ 15] 9 PooledMediaPlayerFactory:acquireMediaPlayer
2020-10-18 13:49:34.084 [ 1f] 9 HTTP2MimeRequestEncoder:getRequestHeaderLines
2020-10-18 13:49:34.084 [ 1f] 9 MessageRequestHandler:getRequestHeaderLines
2020-10-18 13:49:34.084 [ 1f] 9 HTTP2Transport:onActivity:this=0xb52cd10
2020-10-18 13:49:34.084 [ 15] 9 AudioPlayer:configureMediaPlayer:offset=0
2020-10-18 13:49:34.084 [ 15] 9 MediaPlayer:setSourceForUrlCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.084 [ 1f] 0 MessageRequestHandler:EventSent
2020-10-18 13:49:34.084 [  c] 0 MediaPlayer:handleSetSourceForUrlCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.084 [  c] 9 MediaPlayer:tearDownTransientPipelineElements:name=AudioMediaPlayer
2020-10-18 13:49:34.084 [  c] 9 MediaPlayer:getCurrentStreamOffsetCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.084 [  c] 9 MediaPlayer:getCurrentStreamOffsetInvalid:name=AudioMediaPlayer,reason=invalidPipelineState,state=NULL,expectedStates=PAUSED/PLAYING
2020-10-18 13:49:34.094 [  c] 9 ThreadPool:obtainWorker:created=23,obtained=59,releasedToPool=44,releasedFromPool=3,outstanding=12
2020-10-18 13:49:34.094 [  7] 9 TaskThread:startThread:moniker=  7,duration=131
2020-10-18 13:49:34.094 [  c] 0 MediaPlayer:handleSetAttachmentReaderSourceCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.094 [  7] 9 HTTPContentFetcherFactory:create::Creating a new http content fetcher
2020-10-18 13:49:34.094 [  c] 9 MediaPlayer:tearDownTransientPipelineElements:name=AudioMediaPlayer
2020-10-18 13:49:34.094 [  c] 9 MediaPlayer:getCurrentStreamOffsetCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.094 [  c] 9 MediaPlayer:getCurrentStreamOffsetInvalid:name=AudioMediaPlayer,reason=invalidPipelineState,state=NULL,expectedStates=PAUSED/PLAYING
2020-10-18 13:49:34.094 [  7] 9 LibCurlHttpContentFetcher:stateTransition:oldState=INITIALIZED,newState=FETCHING_HEADER:State transition
2020-10-18 13:49:34.094 [  c] 9 BaseStreamSource:initNoAudioFormat
2020-10-18 13:49:34.094 [  c] 5 MediaPlayer:configureSource:fadeIn=fadeIn{ enabled:0, start:100, end:100, duration(ms):0}, normalization{ enabled: 0}, endOffset(ms): 0
2020-10-18 13:49:34.094 [ 15] 5 AudioPlayer:configureMediaPlayer:sourceId=2,audioItemId=amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#306863c6-83b1-4899-8f9c-31adfdd44b17\:1
2020-10-18 13:49:34.094 [ 2b] 9 LibCurlHttpContentFetcher:transferThread::start
2020-10-18 13:49:34.094 [ 15] 9 MediaPlayer:addObserverCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.094 [  c] 0 MediaPlayer:handleAddObserverCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.094 [ 15] I AudioPlayer:executePrePlay:enqueuing=amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#306863c6-83b1-4899-8f9c-31adfdd44b17\:1,sourceId=2,messageId=ee6d86e1-281e-4d5d-bb78-a76f1dd62cec
2020-10-18 13:49:34.094 [ 2b] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2020-10-18 13:49:34.104 [ 2b] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2020-10-18 13:49:34.104 [ 2b] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2020-10-18 13:49:34.124 [ 2b] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2020-10-18 13:49:34.144 [ 2b] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2020-10-18 13:49:34.184 [ 2b] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2020-10-18 13:49:34.184 [ 2b] 9 LibCurlHttpContentFetcher:transferThread::end
2020-10-18 13:49:34.184 [ 2b] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_HEADER,newState=BODY_DONE:State transition
2020-10-18 13:49:34.184 [  7] 0 PlaylistParser:nonSuccessStatusCodeFromGetHeader:statusCode=HTTP_RESPONSE_CODE_UNDEFINED
2020-10-18 13:49:34.184 [  7] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=ERROR
2020-10-18 13:49:34.184 [  7] 9 ThreadPool:obtainWorker:created=23,obtained=60,releasedToPool=44,releasedFromPool=3,outstanding=13
2020-10-18 13:49:34.184 [ 1c] 9 TaskThread:startThread:moniker= 1c,duration=120
2020-10-18 13:49:34.184 [  7] 9 LibCurlHttpContentFetcher:~LibCurlHttpContentFetcher
2020-10-18 13:49:34.184 [ 1c] 9 UrlContentToAttachmentConverter:closingWriter
2020-10-18 13:49:34.184 [ 1c] 0 UrlContentToAttachmentConverter:closeStreamWriter
2020-10-18 13:49:34.184 [ 1c] 9 MediaPlayer:onError:name=AudioMediaPlayer
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:onErrorCallback:name=AudioMediaPlayer
2020-10-18 13:49:34.184 [  c] 0 MediaPlayer:callingOnPlaybackError:name=AudioMediaPlayer,type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=streamingError,currentId=2
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:handleGetOffsetCalled:name=AudioMediaPlayer,idPassed=2,currentId=2
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:getCurrentStreamOffsetCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:getCurrentStreamOffsetInvalid:name=AudioMediaPlayer,reason=invalidPipelineState,state=NULL,expectedStates=PAUSED/PLAYING
2020-10-18 13:49:34.184 [  7] 9 PlaylistParser:playQueueEmpty
2020-10-18 13:49:34.184 [  c] 0 AudioPlayer:onPlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=streamingError,id=2,state=MediaPlayerState: offsetInMilliseconds=-1
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:tearDownTransientPipelineElements:name=AudioMediaPlayer
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:getCurrentStreamOffsetCalled:name=AudioMediaPlayer
2020-10-18 13:49:34.184 [ 15] 1 AudioPlayer:executeOnPlaybackError:id=2,state=MediaPlayerState: offsetInMilliseconds=-1,type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=streamingError
2020-10-18 13:49:34.184 [  c] 9 MediaPlayer:getCurrentStreamOffsetInvalid:name=AudioMediaPlayer,reason=invalidPipelineState,state=NULL,expectedStates=PAUSED/PLAYING
2020-10-18 13:49:34.184 [ 15] W AudioPlayer:executeOnPlaybackError::ErrorWhileBuffering:id=2,state=MediaPlayerState: offsetInMilliseconds=-1
2020-10-18 13:49:34.184 [  c] 9 BaseStreamSource:~BaseStreamSource

full log from Speaking to Idle

Provide the steps to reproduce the issue, if applicable:

Tell Alexa to play radio station

Tell us about your environment:

Followed guide on Set Up the AVS Device SDK on Raspberry Pi

What version of the AVS Device SDK are you using?

  1.20.1

Tell us what hardware you're using:

  • Desktop / Laptop
  • Raspberry Pi
  • Other - tell us more:

Tell us about your OS (Type & version):

  • Linux
  • MacOS
  • Raspbian Stretch
  • Raspbian Jessy
  • Other - tell us more:
    Raspbian Buster
    Windows 64-bit
@alexwala alexwala mentioned this issue Oct 16, 2020
Closed
11 tasks
@alexwala alexwala changed the title Alexa SDK on raspberry pi - tuneIn stopped working Alexa SDK on raspberry pi - tuneIn stopped working - streamingError Oct 19, 2020
@alexwala alexwala changed the title Alexa SDK on raspberry pi - tuneIn stopped working - streamingError Alexa SDK on raspberry pi - TuneIn stopped working - streamingError Oct 19, 2020
@alexwala alexwala changed the title Alexa SDK on raspberry pi - TuneIn stopped working - streamingError Alexa SDK on Raspberry Pi - TuneIn stopped working - streamingError Oct 19, 2020
@alexwala
Copy link
Author

alexwala commented Oct 19, 2020 •
edited

some hints:

  • from TuneIn a m3u file is returned..

If i adapt PlaylistParser.cpp to play content of m3u file streaming is working:
-> Alexa, play BR Heimat
<- Playing BR Heimat on TuneIn

// playItem.playlistURL: http://opml.radiotime.com/Tune.ashx?id=e161653394&sid=s240952&formats=aac,mp3&partnerId=4JqugguZ&serial=AH4YFE6RM4NYPKLNXSHNBGLU3JGA
// content of m3u file : http://addrad.io/444y2zj

//use content of returned m3u file instead of m3u file itself
//auto playlistURL = playItem.playlistURL;
std::string playlistURL ("http://addrad.io/444y2zj");
  • using CURLOPT_VERBOSE - Recv failure: Connection reset by peer:
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Expire in 50 ms for 1 (transfer 0x70f23db0)
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: *   Trying 104.17.106.184...
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * TCP_NODELAY set
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Expire in 14957 ms for 3 (transfer 0x70f23db0)
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Expire in 200 ms for 4 (transfer 0x70f23db0)
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Expire in 0 ms for 6 (transfer 0x70f1e238)
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Connected to opml.radiotime.com (104.17.106.184) port 80 (#0)
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: > GET /Tune.ashx?id=e161653394&sid=s240952&formats=aac,mp3&partnerId=4JqugguZ&serial=AH4YFE6RM4NYPKLNXSHNBGLU3JGA HTTP/1.1
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: Host: opml.radiotime.com
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: User-Agent: AvsDeviceSdk/1.20.1
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: Accept: */*
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: Connection: Upgrade, HTTP2-Settings
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: Upgrade: h2c
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: HTTP2-Settings: AAMAAABkAARAAAAAAAIAAAAA
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: [1B blob data]
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Recv failure: Connection reset by peer
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Closing connection 0
Oct 20 13:12:37 raspberrypi alexa.sh[4163]: * Expire in 0 ms for 6 (transfer 0x70f1e238)
  • curl from command line with HTTP2 - Recv failure: Connection reset by peer:
curl --verbose --http2 "http://opml.radiotime.com/Tune.ashx?id=e161653394&sid=s240952&formats=aac,mp3&partnerId=4JqugguZ&serial=AH4YFE6RM4NYPKLNXSHNBGLU3JGA"

* Expire in 2 ms for 1 (transfer 0x164880)
*   Trying 104.17.107.184...
* TCP_NODELAY set
* Expire in 149997 ms for 3 (transfer 0x164880)
* Expire in 200 ms for 4 (transfer 0x164880)
* Connected to opml.radiotime.com (104.17.107.184) port 80 (#0)
> GET /Tune.ashx?id=e161653394&sid=s240952&formats=aac,mp3&partnerId=4JqugguZ&serial=AH4YFE6RM4NYPKLNXSHNBGLU3JGA HTTP/1.1
> Host: opml.radiotime.com
> User-Agent: curl/7.64.0
> Accept: */*
> Connection: Upgrade, HTTP2-Settings
> Upgrade: h2c
> HTTP2-Settings: AAMAAABkAARAAAAAAAIAAAAA
> 
* Recv failure: Connection reset by peer
* Closing connection 0
curl: (56) Recv failure: Connection reset by peer
  • curl from command line without HTTP2 - OK:
curl --verbose "http://opml.radiotime.com/Tune.ashx?id=e161653394&sid=s240952&formats=aac,mp3&partnerId=4JqugguZ&serial=AH4YFE6RM4NYPKLNXSHNBGLU3JGA"

* Expire in 4 ms for 1 (transfer 0x1714880)
*   Trying 104.17.106.184...
* TCP_NODELAY set
* Expire in 149993 ms for 3 (transfer 0x1714880)
* Expire in 200 ms for 4 (transfer 0x1714880)
* Connected to opml.radiotime.com (104.17.106.184) port 80 (#0)
> GET /Tune.ashx?id=e161653394&sid=s240952&formats=aac,mp3&partnerId=4JqugguZ&serial=AH4YFE6RM4NYPKLNXSHNBGLU3JGA HTTP/1.1
> Host: opml.radiotime.com
> User-Agent: curl/7.64.0
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Tue, 20 Oct 2020 11:38:49 GMT
< Content-Type: audio/x-mpegurl
< Content-Length: 25
< Connection: keep-alive
< Set-Cookie: __cfduid=d0165be60ed35d02dfec1e384364947d31603193929; expires=Thu, 19-Nov-20 11:38:49 GMT; path=/; domain=.radiotime.com; HttpOnly; SameSite=Lax
< x-tunein-dc: us-west-2
< x-envoy-upstream-service-time: 8
< CF-Cache-Status: DYNAMIC
< cf-request-id: 05e76715cb0000fcb1ff2f0000000001
< Server: cloudflare
< CF-RAY: 5e52746949e6fcb1-VIE
< 
http://addrad.io/444y2zj
* Connection #0 to host opml.radiotime.com left intact

so for now temporary removed HTTP2 in LibcurlUtils.cpp – streaming from TuneIn via Alexa works again as usual:

//SETOPT(handle, CURLOPT_HTTP_VERSION, CURL_HTTP_VERSION_2_0) &&

@alexwala alexwala mentioned this issue Oct 21, 2020
Closed
@alexwala
Copy link
Author

cloudflare team mentioned that a fix is already in the works and should be available in due course...
Http h2c upgrade requests result in “Connection reset by peer”

@VaruPan VaruPan mentioned this issue Dec 10, 2020
Closed
7 tasks
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@alexwala