search

patrickkfkan / volumio-ytcr

16 stars 3 forks source link

MPDError: Not connected #9

Open maxdd opened 2 years ago

maxdd commented 2 years ago

Hello, im now facing this issue when using your plugin

[yt-cast-receiver.YouTubeApp] Launching...
[yt-cast-receiver.YouTubeApp] Generated screen Id: 6p53m7smvp57otmi2edvvcq4m2
[yt-cast-receiver.YouTubeApp] Obtained lounge token: AGdO5p9Il4_BrgK4eHx0vWCYki8IB9TwVXwe86FnfHuuLq0xlE5fLH8iJv9v5YgtA2SIpeFSQQn5meDAce3A0rxmMcnWirMvHfau_LjWeZ3AtcnMeyvFwLE
[yt-cast-receiver.YouTubeApp] Initiate binding...
[yt-cast-receiver.YouTubeApp] Processing initial bind data...
[yt-cast-receiver.YouTubeApp] Command #0 - c received with the following data:
[ 'FF4BF8A0394B3229', '', 8 ]
[yt-cast-receiver.YouTubeApp] Setting SID to FF4BF8A0394B3229
[yt-cast-receiver.YouTubeApp] Command #1 - S received with the following data (gsessionid):
5DdoRB2s3CUK-T-fUUOFQnut4HbdV66k
[yt-cast-receiver.YouTubeApp] Command #2 - loungeStatus received but not going to be handled. Skipping...
Unhandled data:
{
  devices: '[{"app":"yt-cast-receiver","capabilities":"que,atp,mus","clientName":"unknown","experiments":"","name":"YouTube Cast Receiver","id":"c8277ac4-ke86-4f8b-8fe2-1236bef43397","type":"LOUNGE_SCREEN","hasCc":"true","receiverIdentityMatchStatus":"IS_RECEIVER"}]',
  connectionEventDetails: '{"deviceId":"c8277ac4-ke86-4f8b-8fe2-1236bef43397"}'
}
[yt-cast-receiver.YouTubeApp] Command #3 - getNowPlaying received. Report 'now playing'...
[yt-cast-receiver.YouTubeApp] Posting bind data:
{ count: '1', ofs: '1', req0__sc: 'noop' }
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 1)
[yt-cast-receiver.YouTubeApp] Registering pairing code with the following data:
URLSearchParams {
  'access_type' => 'permanent',
  'app' => 'yt-cast-receiver',
  'pairing_code' => 'fafa401d-1e32-4672-a819-3ca884f1598a',
  'screen_id' => '6p53m7smvp57otmi2edvvcq4m2',
  'screen_name' => 'YouTube Cast Receiver',
  'device_id' => 'd87e510b-c799-4221-9d24-e23bd96bdb1c' }
[yt-cast-receiver.YouTubeApp] Registered pairing code: fafa401d-1e32-4672-a819-3ca884f1598a
[yt-cast-receiver.CommandListener] Started
[yt-cast-receiver.CommandListener] Listening to: https://www.youtube.com/api/lounge/bc/bind?AID=3&CI=0&CVER=1&RID=rpc&SID=FF4BF8A0394B3229&TYPE=xmlhttp&VER=8&app=yt-cast-receiver&capabilities=que%2Catp%2Cmus&device=LOUNGE_SCREEN&gsessionid=5DdoRB2s3CUK-T-fUUOFQnut4HbdV66k&id=c8277ac4-ke86-4f8b-8fe2-1236bef43397&loungeIdToken=AGdO5p9Il4_BrgK4eHx0vWCYki8IB9TwVXwe86FnfHuuLq0xlE5fLH8iJv9v5YgtA2SIpeFSQQn5meDAce3A0rxmMcnWirMvHfau_LjWeZ3AtcnMeyvFwLE&mdxVersion=2&name=YouTube%20Cast%20Receiver&t=1&theme=cl&v=2&zx=xxxxxxxxxxxx
[yt-cast-receiver.YouTubeApp] Launched
dial: returning pid 2c032fa3-3189-469c-97f4-6b485a02ef48
[yt-cast-receiver.YouTubeApp] Command #4 - noop received but not going to be handled. Skipping...
[yt-cast-receiver.YouTubeApp] Command #5 - loungeStatus received but not going to be handled. Skipping...
Unhandled data:
{
  devices: '[{"app":"yt-cast-receiver","capabilities":"que,atp,mus","clientName":"unknown","experiments":"","name":"YouTube Cast Receiver","id":"c8277ac4-ke86-4f8b-8fe2-1236bef43397","type":"LOUNGE_SCREEN","hasCc":"true","receiverIdentityMatchStatus":"IS_RECEIVER"},{"app":"android-phone-17.03.38","pairingType":"dial","capabilities":"que,dsdtr,atp,mus","clientName":"android","deviceContext":"{\\"user_agent\\":\\"com.vanced.android.youtube\\\\/17.03.38(Linux; U; Android 12; it_IT; KB2003 Build\\\\/RKQ1.211119.001)\\",\\"window_width_points\\":360,\\"window_height_points\\":750,\\"os_name\\":\\"Android\\",\\"ms\\":\\"CoACLLYlVUIthkNJoBBkgehsVNgbvXVrqI0ZLjikDpIpoOYx2RdJKc_NDXMTAb6MauE6dSLnUF5ZBdE1beTLO4AYW4iuuAp7V9-U5ONvooCCxMc49BlDPKlg_9dlugSD9et3GR5YHBAJfAxO5d72PKHt2r4tPdZ2zhVECT2BqiuaDEG5186tsojTz4OK8_WnWCeoKxUMzOB86sa9SZaWgulPYBAmmbHK5f3dQ2yNcT5JrEDUoWqBYwPZSxRwxL2oG4Nhf8Hfm6HUb9QaACArvmd7xcCnWDcWhGuqGiVBAvwgh09mSJDLQmQqafbc0vXb_7wdo9Ny1HRu0kdouuPpkCnkkAqAAvamitHrOh_XlCLl84JtkzPnBbDo4IZQdrFDzduv-7E-idPZ8nidXwGXKlEy_LkJ73YUY6BmD8co9R1O-yY690sLqypCRTXKaXHAxt7XX31eODNwFQ1Bekvg9eFGofw8MY3r6sk32kRM-jr_pJsecQVOJjZfmnyGRM2O23F8QrAqfzWGdV4F7jSLfOGcY2vWaC3ay1Bu6w-bYhTnH-9ZRbVEB9yL4itKbTgI1EAyAoPvWoct7B84LVG8kdJSZiigikSqT7SpKcbp11Mu2IUwJCO9NDiiCfVhhEKf-g7nOwqkuiOtpDc7UZxNwoe3DS3JdJlqHUhiN4qWjLwZEVM6F9wSEP_zpS_yghdtLxRxItsplXg\\"}","experiments":"","name":"ONEPLUS KB2003","id":"vap5k6htltnk4co6ekfchco750","type":"REMOTE_CONTROL","localChannelEncryptionKey":"wO4d1niThjOQLjmrDhybcNF0kdahPX3mZC4W6PJ_RTk","receiverIdentityMatchStatus":"MATCHES_RECEIVER"}]',
  connectionEventDetails: '{"ui":"true","hasInitialPlayback":"false","deviceId":"vap5k6htltnk4co6ekfchco750"}'
}
[yt-cast-receiver.YouTubeApp] Command #6 - remoteConnected received with the following client data:
{
  app: 'android-phone-17.03.38',
  pairingType: 'dial',
  capabilities: 'que,dsdtr,atp,mus',
  ui: 'true',
  clientName: 'android',
  deviceContext: '{"user_agent":"com.vanced.android.youtube\\/17.03.38(Linux; U; Android 12; it_IT; KB2003 Build\\/RKQ1.211119.001)","window_width_points":360,"window_height_points":750,"os_name":"Android","ms":"CoACLLYlVUIthkNJoBBkgehsVNgbvXVrqI0ZLjikDpIpoOYx2RdJKc_NDXMTAb6MauE6dSLnUF5ZBdE1beTLO4AYW4iuuAp7V9-U5ONvooCCxMc49BlDPKlg_9dlugSD9et3GR5YHBAJfAxO5d72PKHt2r4tPdZ2zhVECT2BqiuaDEG5186tsojTz4OK8_WnWCeoKxUMzOB86sa9SZaWgulPYBAmmbHK5f3dQ2yNcT5JrEDUoWqBYwPZSxRwxL2oG4Nhf8Hfm6HUb9QaACArvmd7xcCnWDcWhGuqGiVBAvwgh09mSJDLQmQqafbc0vXb_7wdo9Ny1HRu0kdouuPpkCnkkAqAAvamitHrOh_XlCLl84JtkzPnBbDo4IZQdrFDzduv-7E-idPZ8nidXwGXKlEy_LkJ73YUY6BmD8co9R1O-yY690sLqypCRTXKaXHAxt7XX31eODNwFQ1Bekvg9eFGofw8MY3r6sk32kRM-jr_pJsecQVOJjZfmnyGRM2O23F8QrAqfzWGdV4F7jSLfOGcY2vWaC3ay1Bu6w-bYhTnH-9ZRbVEB9yL4itKbTgI1EAyAoPvWoct7B84LVG8kdJSZiigikSqT7SpKcbp11Mu2IUwJCO9NDiiCfVhhEKf-g7nOwqkuiOtpDc7UZxNwoe3DS3JdJlqHUhiN4qWjLwZEVM6F9wSEP_zpS_yghdtLxRxItsplXg"}',
  experiments: '',
  name: 'ONEPLUS KB2003',
  id: 'vap5k6htltnk4co6ekfchco750',
  type: 'REMOTE_CONTROL',
  device: '{"app":"android-phone-17.03.38","pairingType":"dial","capabilities":"que,dsdtr,atp,mus","clientName":"android","deviceContext":"{\\"user_agent\\":\\"com.vanced.android.youtube\\\\/17.03.38(Linux; U; Android 12; it_IT; KB2003 Build\\\\/RKQ1.211119.001)\\",\\"window_width_points\\":360,\\"window_height_points\\":750,\\"os_name\\":\\"Android\\",\\"ms\\":\\"CoACLLYlVUIthkNJoBBkgehsVNgbvXVrqI0ZLjikDpIpoOYx2RdJKc_NDXMTAb6MauE6dSLnUF5ZBdE1beTLO4AYW4iuuAp7V9-U5ONvooCCxMc49BlDPKlg_9dlugSD9et3GR5YHBAJfAxO5d72PKHt2r4tPdZ2zhVECT2BqiuaDEG5186tsojTz4OK8_WnWCeoKxUMzOB86sa9SZaWgulPYBAmmbHK5f3dQ2yNcT5JrEDUoWqBYwPZSxRwxL2oG4Nhf8Hfm6HUb9QaACArvmd7xcCnWDcWhGuqGiVBAvwgh09mSJDLQmQqafbc0vXb_7wdo9Ny1HRu0kdouuPpkCnkkAqAAvamitHrOh_XlCLl84JtkzPnBbDo4IZQdrFDzduv-7E-idPZ8nidXwGXKlEy_LkJ73YUY6BmD8co9R1O-yY690sLqypCRTXKaXHAxt7XX31eODNwFQ1Bekvg9eFGofw8MY3r6sk32kRM-jr_pJsecQVOJjZfmnyGRM2O23F8QrAqfzWGdV4F7jSLfOGcY2vWaC3ay1Bu6w-bYhTnH-9ZRbVEB9yL4itKbTgI1EAyAoPvWoct7B84LVG8kdJSZiigikSqT7SpKcbp11Mu2IUwJCO9NDiiCfVhhEKf-g7nOwqkuiOtpDc7UZxNwoe3DS3JdJlqHUhiN4qWjLwZEVM6F9wSEP_zpS_yghdtLxRxItsplXg\\"}","experiments":"","name":"ONEPLUS KB2003","id":"vap5k6htltnk4co6ekfchco750","type":"REMOTE_CONTROL","receiverIdentityMatchStatus":"MATCHES_RECEIVER"}',
  receiverIdentityMatchStatus: 'MATCHES_RECEIVER'
}
[yt-cast-receiver.YouTubeApp] Posting bind data:
{
  count: '1',
  ofs: '2',
  req0__sc: 'onAutoplayModeChanged',
  req0_autoplayMode: 'ENABLED'
}
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 2)
[yt-cast-receiver.YouTubeApp] Refresh autoplay Up Next
[yt-cast-receiver.YouTubeApp] Posting bind data:
{ count: '1', ofs: '3', req0__sc: 'autoplayUpNext' }
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 3)
info: [ytcr] ***** Connected *****
info: CoreCommandRouter::getUIConfigOnPlugin
[yt-cast-receiver.YouTubeApp] Command #7 - getNowPlaying received. Report 'now playing'...
[yt-cast-receiver.YouTubeApp] Posting bind data:
{ count: '1', ofs: '4', req0__sc: 'noop' }
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 4)
[yt-cast-receiver.YouTubeApp] Command #8 - getSubtitlesTrack received but not going to be handled. Skipping...
[yt-cast-receiver.YouTubeApp] Command #9 - getVolume received. Reporting volume...
[yt-cast-receiver.YouTubeApp] Posting bind data:
{ count: '1', ofs: '5', req0__sc: 'noop' }
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 5)
[yt-cast-receiver.YouTubeApp] Keeping alive...
[yt-cast-receiver.YouTubeApp] Posting bind data:
{ count: '1', ofs: '6', req0__sc: 'noop' }
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 6)
[yt-cast-receiver.YouTubeApp] Command #10 - setPlaylist received with the following data:
{
  listId: 'RQ077mtdnwAvXNTtcDjjhIQWgu3jE',
  currentTime: '0',
  eventDetails: '{"videoId":"kTJczUoc26U","eventType":"VIDEO_ADDED"}',
  sourceDeviceType: 'REMOTE_CONTROL',
  audioOnly: 'false',
  videoId: 'kTJczUoc26U',
  playerParams: '',
  prioritizeMobileSenderPlaybackStateOnConnection: 'true',
  params: '',
  videoIds: 'kTJczUoc26U',
  currentIndex: '0',
  csn: 'IkCM4AGnWQkziBiPl-Bslg=='
}
[yt-cast-receiver.YouTubeApp] Requesting player to play video ID kTJczUoc26U at position 0s
[yt-cast-receiver.YouTubeApp] Reporting change in player state...
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 1
[ytcr] play command received while not being the current service.
[ytcr] Stopping playback by current service...
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined

info: CoreStateMachine::updateTrackBlock
info: CorePlayQueue::getTrackBlock
info: CoreStateMachine::stPlaybackTimer
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 1
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreStateMachine::serviceStop
info: CorePlayQueue::getTrack 1
info: CoreCommandRouter::serviceStop
info: ControllerMpd::stop

[MPDPlayer] Play kTJczUoc26U at position 0s
[MPDPlayer] is asleep - returning stopped status
[MPDPlayer] loadPlayData(kTJczUoc26U)
[yt-cast-receiver.YouTubeApp] Posting bind data:
{
  count: '1',
  ofs: '7',
  req0__sc: 'onStateChange',
  req0_currentTime: '0',
  req0_duration: '0',
  req0_cpn: 'foo',
  req0_loadedTime: '0',
  req0_state: '3',
  req0_seekableStartTime: '0',
  req0_seekableEndTime: '0'
}
info: sendMpdCommand stop took 30 milliseconds
[ytcr] Setting ourselves as the current service...
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 1
info: CoreStateMachine::setConsumeUpdateService undefined
[ytcr] Pushing empty state...
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[yt-cast-receiver.YouTubeApp] Posting bind data:
{
  count: '1',
  ofs: '8',
  req0__sc: 'onVolumeChanged',
  req0_volume: '0',
  req0_muted: 'false'
}
info: Ignoring MPD Status Update
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 7)
WARNING: ytdl-core is out of date! Update with "npm install ytdl-core@latest".
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 8)
[MPDPlayer] checkAudioUrl(): https://rr3---sn-uxaxpu5ap5-c1ve.googlevideo.com/videoplayback?expire=1665161864&ei=KAZAY7y3HZDN1gKl2pHQBw&ip=95.237.65.63&id=o-AJnnoFc6BSRBieoPhjhwasKFVQIRccil3PX9bBzJae2u&itag=251&source=youtube&requiressl=yes&mh=1j&mm=31%2C29&mn=sn-uxaxpu5ap5-c1ve%2Csn-hpa7zn7d&ms=au%2Crdu&mv=m&mvi=3&pl=24&gcr=it&initcwndbps=1331250&vprv=1&mime=audio%2Fwebm&gir=yes&clen=2703258&dur=157.681&lmt=1647988464572692&mt=1665139771&fvip=3&keepalive=yes&fexp=24001373%2C24007246&c=WEB&txp=4532434&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cgcr%2Cvprv%2Cmime%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AG3C_xAwQwIfQsD25ip1JiYRaPlK2jJbDTkT7EcMleLbw6AX2tn-1AIgPZ9awxst6aqBhkTEvKTGAePWOPCpgH7uGUZpDigz88Y%3D&ratebypass=yes&sig=AOq0QJ8wRQIhAKmEk_V8apoJWLu-qz78mXbVq7ZysNO2qShkkKD3_fdDAiB1058OlM0aoXzAu1ZtiywwyGqUC2RnmaIvh7CXaWuQUw%3D%3D
[MPDPlayer] checkAudioUrl() passed. Response status code: 200
[MPDPlayer] Loaded track for kTJczUoc26U:
{
  playable: true,
  thumbnail: 'https://i.ytimg.com/vi/kTJczUoc26U/maxresdefault.jpg?v=60e73455',
  videoId: 'kTJczUoc26U',
  title: 'The Kid LAROI, Justin Bieber - STAY (Official Video)',
  channelTitle: 'TheKidLAROIVEVO',
  duration: '158',
  streamUrl: 'https://rr3---sn-uxaxpu5ap5-c1ve.googlevideo.com/videoplayback?expire=1665161864&ei=KAZAY7y3HZDN1gKl2pHQBw&ip=95.237.65.63&id=o-AJnnoFc6BSRBieoPhjhwasKFVQIRccil3PX9bBzJae2u&itag=251&source=youtube&requiressl=yes&mh=1j&mm=31%2C29&mn=sn-uxaxpu5ap5-c1ve%2Csn-hpa7zn7d&ms=au%2Crdu&mv=m&mvi=3&pl=24&gcr=it&initcwndbps=1331250&vprv=1&mime=audio%2Fwebm&gir=yes&clen=2703258&dur=157.681&lmt=1647988464572692&mt=1665139771&fvip=3&keepalive=yes&fexp=24001373%2C24007246&c=WEB&txp=4532434&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cgcr%2Cvprv%2Cmime%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=mh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps&lsig=AG3C_xAwQwIfQsD25ip1JiYRaPlK2jJbDTkT7EcMleLbw6AX2tn-1AIgPZ9awxst6aqBhkTEvKTGAePWOPCpgH7uGUZpDigz88Y%3D&ratebypass=yes&sig=AOq0QJ8wRQIhAKmEk_V8apoJWLu-qz78mXbVq7ZysNO2qShkkKD3_fdDAiB1058OlM0aoXzAu1ZtiywwyGqUC2RnmaIvh7CXaWuQUw%3D%3D',
  channels: 2,
  bitrate: 160,
  isLive: false
}
(node:431) UnhandledPromiseRejectionWarning: MPDError: Not connected
    at MPDClient.send (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:100:13)
    at MPDClient.stopIdling (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:81:10)
    at MPDClient.sendCommand (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:63:10)
    at Object.clear (/data/plugins/music_service/ytcr/node_modules/mpd-api/lib/api/index.js:60:16)
    at MPDPlayer.play (/data/plugins/music_service/ytcr/lib/mpd-player.js:160:40)
    at runMicrotasks ()
    at processTicksAndRejections (internal/process/task_queues.js:95:5)
    at async Promise.all (index 1)
    at async YouTubeApp._playCurrentInList (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/lib/app.js:736:13)
    at async YouTubeApp._handleCmd (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/lib/app.js:392:13)
    at async /data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/lib/app.js:902:33
(Use `node --trace-warnings ...` to show where the warning was created)
(node:431) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3)
(node:431) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
[yt-cast-receiver.YouTubeApp] Keeping alive...
[yt-cast-receiver.YouTubeApp] Posting bind data:
{
  count: '1',
  ofs: '9',
  req0__sc: 'nowPlaying',
  req0_currentTime: '0',
  req0_duration: '0',
  req0_cpn: 'foo',
  req0_loadedTime: '0',
  req0_state: '3',
  req0_seekableStartTime: '0',
  req0_seekableEndTime: '0',
  req0_listId: 'RQ077mtdnwAvXNTtcDjjhIQWgu3jE',
  req0_videoId: 'kTJczUoc26U',
  req0_currentIndex: '0'
}
[yt-cast-receiver.YouTubeApp] postBind() completed (ofs: 9)

shall i

npm install ytdl-core@latest

as per the log?

My version is

image

image

The main way i use to recover from this is to restart the plugin but i have no idea why MPD is not connected

patrickkfkan commented 2 years ago

The problem is this:

(node:431) UnhandledPromiseRejectionWarning: MPDError: Not connected

Is it possible to run a fresh installation of Volumio for testing purpose, perhaps on another SD card / USB stick?

maxdd commented 2 years ago

The installation is fresh in the sense that to try to solve this issue i've tried reflashing 3-4 times already but it happened from time to time. Can you elaborate on the error? When it happens should i launch a command to verify what's the MPD process doing, if it is dead is it more a "Volumio" thing? Maybe i can activated MPD log to see why it is going down, how is it done the connection to MPD, via socket?