2020-02-05T16:14:11.496722+00:00 heroku[web.1]: State changed from down to starting
2020-02-05T16:14:19.695144+00:00 heroku[web.1]: Starting process with command `python3 server.py`
2020-02-05T16:14:24.578179+00:00 heroku[web.1]: State changed from starting to up
2020-02-05T16:14:24.228001+00:00 app[web.1]:  * Running on http://0.0.0.0:31768/ (Press CTRL+C to quit)
2020-02-05T16:14:24.229457+00:00 app[web.1]:  * Restarting with stat
2020-02-05T16:14:26.887148+00:00 app[web.1]:  * Debugger is active!
2020-02-05T16:14:26.888180+00:00 app[web.1]:  * Debugger PIN: 257-579-375
2020-02-05T16:14:27.241276+00:00 heroku[router]: at=info method=POST path="/alexa" host=albismusic.herokuapp.com request_id=45620837-f118-4a27-b5ad-05db17182b63 fwd="54.240.197.118" dyno=web.1 connect=1ms service=1500ms status=200 bytes=602 protocol=https
2020-02-05T16:14:27.237292+00:00 app[web.1]: 10.13.244.211 - - [05/Feb/2020 16:14:27] "POST /alexa HTTP/1.1" 200 -
2020-02-05T16:14:27.546336+00:00 app[web.1]: 10.15.154.196 - - [05/Feb/2020 16:14:27] "POST /alexa HTTP/1.1" 200 -
2020-02-05T16:14:27.551699+00:00 heroku[router]: at=info method=POST path="/alexa" host=albismusic.herokuapp.com request_id=4fdf8706-dc7c-49bb-92a7-2b95a69f1d43 fwd="54.240.197.72" dyno=web.1 connect=0ms service=1770ms status=200 bytes=153 protocol=https
2020-02-05T16:14:32.524598+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:32.524611+00:00 app[web.1]: DEBUG in music [/app/geemusic/utils/music.py:39]:
2020-02-05T16:14:32.524614+00:00 app[web.1]: Fetching library complete.
2020-02-05T16:14:32.524621+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:34.392988+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:34.393001+00:00 app[web.1]: DEBUG in music [/app/geemusic/utils/music.py:39]:
2020-02-05T16:14:34.393003+00:00 app[web.1]: Fetching library complete.
2020-02-05T16:14:34.393009+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:37.376668+00:00 app[web.1]: 10.33.38.71 - - [05/Feb/2020 16:14:37] "POST /alexa HTTP/1.1" 200 -
2020-02-05T16:14:37.381146+00:00 heroku[router]: at=info method=POST path="/alexa" host=albismusic.herokuapp.com request_id=c5c79125-3e9a-4950-9761-5afc1f671722 fwd="54.240.197.22" dyno=web.1 connect=0ms service=317ms status=200 bytes=602 protocol=https
2020-02-05T16:14:48.444693+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:48.444705+00:00 app[web.1]: DEBUG in music [/app/geemusic/utils/music.py:39]:
2020-02-05T16:14:48.444706+00:00 app[web.1]: Finding closest match...
2020-02-05T16:14:48.444713+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:48.445050+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:48.445053+00:00 app[web.1]: DEBUG in music [/app/geemusic/utils/music.py:39]:
2020-02-05T16:14:48.445125+00:00 app[web.1]: Found {'kind': 'sj#playlist', 'id': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'creationTimestamp': '1580318593125600', 'lastModifiedTimestamp': '1580318604786824', 'recentTimestamp': '1580318592541000', 'deleted': False, 'name': 'Good', 'type': 'USER_GENERATED', 'shareToken': 'AMaBXykH-F0AAOIs8YIq-stBPGbvFosDoBHPagomvMP5Oy27up-IKyV4Yfzt3BKzUopn1fyR7cTmYtausd4vrxWDQPNV5n4Kbw==', 'ownerName': 'albis mendis', 'description': '', 'accessControlled': False, 'tracks': [{'kind': 'sj#playlistEntry', 'id': 'fc28a414-b447-30bb-b4fc-2eec79e2386d', 'clientId': 'e3ffcfbc-619c-48c7-bd87-bcc4ef73cd77', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01220740416642543855', 'trackId': 'da3fa2db-2f26-3665-8b85-c616a90010bb', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': '362225b0-53a0-3569-80b0-a2efd09b14da', 'clientId': '5fb599d3-9bb0-461c-9edf-fe590e7b7270', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01288559328678240735', 'trackId': '6d949d49-925e-34ce-b2c1-cadf4c9f839a', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': '15f0402d-0fd9-32ef-8b6b-55024af37f9e', 'clientId': '567efc4a-4a8d-4bc6-b885-5ac177dd2bef', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01356378240713937615', 'trackId': '9f0d9475-e4f7-3fdf-b2c1-14306cdc700e', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'f6ab7df1-caad-3537-8f02-4d99f4b27bb0', 'clientId': '1ef67af0-130e-470d-a8f4-d9b9e80ed4aa', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01424197152749634495', 'trackId': '65e6319a-52d2-3005-860a-38eff6118c17', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': '96a7be1e-932a-3928-8e56-35fd906101f0', 'clientId': '67dcb294-a3db-472c-b328-81ec851f5be1', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01492016064785331375', 'trackId': '30ac0fcc-e1c7-34ba-a78d-59f16ce2d459', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'f78c6bd3-4e29-3f63-8f5a-b5bda5ab5a26', 'clientId': '351cd953-37c8-4f96-8fea-fde23062926a', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01559834976821028255', 'trackId': '86d572b2-85a8-3d30-b408-e5a42a4771d5', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'ccf24d21-f6c7-3cf5-b7f1-ea714af3c9da', 'clientId': 'aa4c0efc-13fa-4c97-89b1-acad3c6829d7', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01627653888856725135', 'trackId': '0835dcc6-89d3-3e36-b8cb-2e84b318d1db', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'c6496422-b025-3851-b77d-40dc4e5c2e79', 'clientId': '99fc62d2-af44-432b-841a-b1b05794c9dd', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01695472800892422015', 'trackId': '85574bb8-55ce-31b5-988a-27868977d243', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'e89d2e82-6b1e-3eff-a50b-e0ac7ce9ea10', 'clientId': '4137fe90-4b0a-4073-aa31-080e07a5eeb6', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01763291712928118895', 'trackId': 'aec4c3b1-a428-3f13-a4b4-0802310d3477', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': '3ccb8b0b-37f7-3a75-8f83-e8e04c69a0c7', 'clientId': '92c1eea4-75f9-4026-84f7-45e80a8e0f82', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01831110624963815775', 'trackId': 'c814b684-46dc-3be8-b160-fdc6ffc61402', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': '7841b5b6-6f8d-36f3-ae21-901f9687eece', 'clientId': '11c67565-3d85-4a81-a1ef-4c65186d5be0', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01898929536999512655', 'trackId': 'd38aef9f-3b55-352c-ae58-3b2e48078b46', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'dea10e91-c605-3562-a8d4-fe42470623df', 'clientId': 'c97d1ec0-b747-45a9-afa6-7b23d49c9d10', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '01966748449035209535', 'trackId': '3e022154-82a8-30d1-a377-3875d20855b2', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'c6f15a89-366f-3b79-ae3c-f9c3037f744d', 'clientId': '2ada04ed-7fc9-41c1-b87c-9eb9551aed99', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '02034567361070906415', 'trackId': '1e2abb0b-f758-3d62-b6ff-866225220e26', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'fe4b62f2-e4af-36da-927b-cde6819e719a', 'clientId': '0f097847-ba7c-42b4-a62d-71c1eb47d4e3', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '02102386273106603295', 'trackId': '0f1e486f-e469-3237-b62c-1b28d629b112', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': 'f0fcb07b-c291-3e13-bab9-15fa9e400d4f', 'clientId': '52df4754-18cc-47c8-ba29-1a5484d47e7f', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '02170205185142300175', 'trackId': 'c3e8bf57-e9d4-302f-bbbd-366784ceaf53', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}, {'kind': 'sj#playlistEntry', 'id': '34475155-967e-35c5-8db7-3efc3076f958', 'clientId': '3f3021d7-ab62-4ab3-b72a-b63c10ef588c', 'playlistId': '4a451a2a-2f54-41be-87a6-475fce0feeae', 'absolutePosition': '02238024097177997055', 'trackId': '9ba59308-2361-376e-972a-4182dab83adb', 'creationTimestamp': '1580318604685000', 'lastModifiedTimestamp': '1580318604685000', 'deleted': False, 'source': '1'}]}...
2020-02-05T16:14:48.445127+00:00 app[web.1]: --------------------------------------------------------------------------------
2020-02-05T16:14:48.459622+00:00 app[web.1]: 10.10.68.189 - - [05/Feb/2020 16:14:48] "POST /alexa HTTP/1.1" 500 -
2020-02-05T16:14:48.460146+00:00 app[web.1]: Traceback (most recent call last):
2020-02-05T16:14:48.460147+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1997, in __call__
2020-02-05T16:14:48.460149+00:00 app[web.1]:     return self.wsgi_app(environ, start_response)
2020-02-05T16:14:48.460150+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1985, in wsgi_app
2020-02-05T16:14:48.460151+00:00 app[web.1]:     response = self.handle_exception(e)
2020-02-05T16:14:48.460153+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1540, in handle_exception
2020-02-05T16:14:48.460155+00:00 app[web.1]:     reraise(exc_type, exc_value, tb)
2020-02-05T16:14:48.460156+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/_compat.py", line 33, in reraise
2020-02-05T16:14:48.460158+00:00 app[web.1]:     raise value
2020-02-05T16:14:48.460159+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1982, in wsgi_app
2020-02-05T16:14:48.460160+00:00 app[web.1]:     response = self.full_dispatch_request()
2020-02-05T16:14:48.460161+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1614, in full_dispatch_request
2020-02-05T16:14:48.460163+00:00 app[web.1]:     rv = self.handle_user_exception(e)
2020-02-05T16:14:48.460164+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1517, in handle_user_exception
2020-02-05T16:14:48.460167+00:00 app[web.1]:     reraise(exc_type, exc_value, tb)
2020-02-05T16:14:48.460167+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/_compat.py", line 33, in reraise
2020-02-05T16:14:48.460169+00:00 app[web.1]:     raise value
2020-02-05T16:14:48.460171+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1612, in full_dispatch_request
2020-02-05T16:14:48.460173+00:00 app[web.1]:     rv = self.dispatch_request()
2020-02-05T16:14:48.460173+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask/app.py", line 1598, in dispatch_request
2020-02-05T16:14:48.460175+00:00 app[web.1]:     return self.view_functions[rule.endpoint](**req.view_args)
2020-02-05T16:14:48.460176+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.6/site-packages/flask_ask/core.py", line 767, in _flask_view_func
2020-02-05T16:14:48.460178+00:00 app[web.1]:     result = self._map_intent_to_view_func(self.request.intent)()
2020-02-05T16:14:48.460179+00:00 app[web.1]:   File "/app/geemusic/intents/selection.py", line 295, in play_playlist
2020-02-05T16:14:48.460180+00:00 app[web.1]:     first_song_id = queue.reset(best_match['tracks'])
2020-02-05T16:14:48.460182+00:00 app[web.1]:   File "/app/geemusic/utils/music_queue.py", line 50, in reset
2020-02-05T16:14:48.460184+00:00 app[web.1]:     return self.get_or_create_queue(context.System.device.deviceId).reset(tracks)
2020-02-05T16:14:48.460185+00:00 app[web.1]:   File "/app/geemusic/utils/music_queue.py", line 120, in reset
2020-02-05T16:14:48.460187+00:00 app[web.1]:     track, song_id = self.api.extract_track_info(track)
2020-02-05T16:14:48.460188+00:00 app[web.1]:   File "/app/geemusic/utils/music.py", line 262, in extract_track_info
2020-02-05T16:14:48.460189+00:00 app[web.1]:     return self.library[track['id']], track['id']
2020-02-05T16:14:48.460191+00:00 app[web.1]: KeyError: 'fc28a414-b447-30bb-b4fc-2eec79e2386d'
2020-02-05T16:14:48.465179+00:00 heroku[router]: at=info method=POST path="/alexa" host=albismusic.herokuapp.com request_id=f8e0055d-cab4-404b-af15-0f121bb880bf fwd="54.240.197.80" dyno=web.1 connect=3ms service=1091ms status=500 bytes=26886 protocol=https
2020-02-05T16:14:49.167783+00:00 app[web.1]: 10.32.165.53 - - [05/Feb/2020 16:14:49] "POST /alexa HTTP/1.1" 200 -
2020-02-05T16:14:49.174561+00:00 heroku[router]: at=info method=POST path="/alexa" host=albismusic.herokuapp.com request_id=6f0967e7-185c-48e7-9221-70765ae1b3ac fwd="54.240.197.72" dyno=web.1 connect=1ms service=323ms status=200 bytes=153 protocol=https