-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Fri 2024-10-04 18:47:52 CEST. -- Oct 04 18:46:00 tomsvolumio kernel: hwmon hwmon1: Undervoltage detected! Oct 04 18:46:04 tomsvolumio volumio[991]: info: Executing endpoint cdPostRip Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , notifyPostRip Oct 04 18:46:04 tomsvolumio volumio[991]: info: CD RIP Terminated Oct 04 18:46:04 tomsvolumio volumio[991]: info: Set CD Speed to 4X Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:46:04 tomsvolumio volumio[991]: info: Oct 04 18:46:04 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: update Oct 04 18:46:04 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:46:04 tomsvolumio volumio[991]: info: Updating MPD DB after CD rip Oct 04 18:46:04 tomsvolumio volumio[991]: info: Cleaning abcde folders after CD rip Oct 04 18:46:04 tomsvolumio volumio[991]: info: sendMpdCommand status took 17 milliseconds Oct 04 18:46:04 tomsvolumio volumio[991]: info: sendMpdCommand status took 15 milliseconds Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:46:04 tomsvolumio kernel: sr 2:0:0:0: ioctl_internal_command: ILLEGAL REQUEST asc=0x53 ascq=0x2 Oct 04 18:46:04 tomsvolumio volumio[991]: info: Command Router : Notfying DB Updatetrue Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreCommandRouter::Close All Modals sent Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:46:04 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:46:04 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:46:04 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":253508,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"701 Kbps","isStreaming":false,"title":"356980314&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980314&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:46:04 tomsvolumio volumio[991]: verbose: CURRENT POSITION 4 Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:46:04 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:46:04 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:46:04 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:46:04 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:46:04 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:04 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:46:04 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:46:04 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:46:05 tomsvolumio volumio[991]: info: ------------------------------ 660ms Oct 04 18:46:05 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:46:05 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:46:05 tomsvolumio volumio[991]: info: Syncing changes to disk Oct 04 18:46:07 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:46:07 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:07 tomsvolumio volumio[991]: info: Clearing queue from CD entries Oct 04 18:46:07 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushQueue Oct 04 18:46:07 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesAudio CD Oct 04 18:46:07 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 04 18:46:07 tomsvolumio volumio[991]: Cannot find translation for source Spotify Oct 04 18:46:07 tomsvolumio volumio[991]: Cannot find translation for source TIDAL Oct 04 18:46:11 tomsvolumio kernel: hwmon hwmon1: Voltage normalised Oct 04 18:46:12 tomsvolumio volumio[991]: info: CD Rip Successfully started Oct 04 18:46:12 tomsvolumio volumio[991]: info: MPD Database updated - AlbumList cache refreshed Oct 04 18:46:12 tomsvolumio volumio[991]: info: Oct 04 18:46:12 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: database Oct 04 18:46:12 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:46:12 tomsvolumio volumio[991]: info: Oct 04 18:46:12 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: update Oct 04 18:46:12 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:46:12 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:46:12 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:46:12 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:46:13 tomsvolumio volumio[991]: info: sendMpdCommand status took 682 milliseconds Oct 04 18:46:13 tomsvolumio volumio[991]: info: sendMpdCommand status took 681 milliseconds Oct 04 18:46:13 tomsvolumio volumio[991]: info: sendMpdCommand status took 680 milliseconds Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:46:13 tomsvolumio volumio[991]: info: Command Router : Notfying DB Updatefalse Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::Close All Modals sent Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:46:13 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 04 18:46:13 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:46:13 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":261768,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"646 Kbps","isStreaming":false,"title":"356980314&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980314&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: CURRENT POSITION 4 Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:46:13 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:46:13 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":261768,"duration":318,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"646 Kbps","isStreaming":false,"title":"356980314&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980314&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:46:13 tomsvolumio volumio[991]: verbose: CURRENT POSITION 4 Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:46:13 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:13 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:46:13 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:46:13 tomsvolumio volumio[991]: info: ------------------------------ 845ms Oct 04 18:46:13 tomsvolumio volumio[991]: info: ------------------------------ 845ms Oct 04 18:46:13 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:46:13 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:46:13 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:46:13 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:46:38 tomsvolumio kernel: hwmon hwmon1: Undervoltage detected! Oct 04 18:46:42 tomsvolumio sudo[6163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /dev/sr0 Oct 04 18:46:42 tomsvolumio sudo[6163]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:42 tomsvolumio sudo[6163]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:42 tomsvolumio sudo[6166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /dev/sr1 Oct 04 18:46:42 tomsvolumio sudo[6166]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:42 tomsvolumio sudo[6166]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:42 tomsvolumio volumio[991]: /bin/chmod: cannot access '/dev/sr1': No such file or directory Oct 04 18:46:42 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 04 18:46:42 tomsvolumio volumio[991]: info: [1728060402935] CoreMusicLibrary::Adding element Audio CD Oct 04 18:46:42 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 04 18:46:42 tomsvolumio volumio[991]: Cannot find translation for source Spotify Oct 04 18:46:42 tomsvolumio volumio[991]: Cannot find translation for source TIDAL Oct 04 18:46:42 tomsvolumio volumio[991]: Cannot find translation for source Audio CD Oct 04 18:46:42 tomsvolumio volumio[991]: info: Set CD Speed to 4X Oct 04 18:46:44 tomsvolumio kernel: hwmon hwmon1: Voltage normalised Oct 04 18:46:46 tomsvolumio kernel: hwmon hwmon1: Undervoltage detected! Oct 04 18:46:46 tomsvolumio volumio[991]: info: Tunnel connection is inactive, restarting it Oct 04 18:46:46 tomsvolumio volumio[991]: info: Starting Tunnel 1 Oct 04 18:46:46 tomsvolumio volumio[991]: info: Starting Tunnel Connection Checker Oct 04 18:46:47 tomsvolumio sudo[6320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 04 18:46:47 tomsvolumio sudo[6320]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:47 tomsvolumio autossh[5459]: received signal to exit (15) Oct 04 18:46:47 tomsvolumio systemd[1]: Stopping MyVolumio SSH Tunnel... Oct 04 18:46:47 tomsvolumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Oct 04 18:46:47 tomsvolumio systemd[1]: sshtunnel.service: Succeeded. Oct 04 18:46:47 tomsvolumio systemd[1]: Stopped MyVolumio SSH Tunnel. Oct 04 18:46:47 tomsvolumio volumio[991]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 04 18:46:47 tomsvolumio volumio[991]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 04 18:46:47 tomsvolumio systemd[1]: Started MyVolumio SSH Tunnel. Oct 04 18:46:47 tomsvolumio sudo[6320]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:47 tomsvolumio volumio[991]: info: Remote SSH Started Oct 04 18:46:47 tomsvolumio autossh[6324]: port set to 0, monitoring disabled Oct 04 18:46:47 tomsvolumio autossh[6324]: starting ssh (count 1) Oct 04 18:46:47 tomsvolumio autossh[6324]: ssh child pid is 6327 Oct 04 18:46:47 tomsvolumio volumio[991]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 04 18:46:47 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:46:47 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:50 tomsvolumio volumio[991]: info: CDDB Entry Already exists Oct 04 18:46:50 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 04 18:46:50 tomsvolumio volumio[991]: info: [1728060410779] CoreMusicLibrary::Adding element Audio CD Oct 04 18:46:50 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 04 18:46:50 tomsvolumio volumio[991]: Cannot find translation for source Spotify Oct 04 18:46:50 tomsvolumio volumio[991]: Cannot find translation for source TIDAL Oct 04 18:46:50 tomsvolumio volumio[991]: Cannot find translation for source Audio CD Oct 04 18:46:55 tomsvolumio kernel: hwmon hwmon1: Voltage normalised Oct 04 18:46:56 tomsvolumio sudo[6685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 04 18:46:56 tomsvolumio sudo[6685]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:56 tomsvolumio sudo[6687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 04 18:46:56 tomsvolumio sudo[6687]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:56 tomsvolumio sudo[6685]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:56 tomsvolumio sudo[6687]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:56 tomsvolumio volumio[991]: verbose: New Socket.io Connection to 192.168.100.78 from 192.168.100.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:131.0) Gecko/20100101 Firefox/131.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 04 18:46:57 tomsvolumio kernel: hwmon hwmon1: Undervoltage detected! Oct 04 18:46:57 tomsvolumio sudo[6691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 04 18:46:57 tomsvolumio sudo[6691]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:57 tomsvolumio sudo[6691]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:57 tomsvolumio sudo[6693]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 04 18:46:57 tomsvolumio sudo[6693]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:46:57 tomsvolumio sudo[6693]: pam_unix(sudo:session): session closed for user root Oct 04 18:46:57 tomsvolumio volumio[991]: verbose: New Socket.io Connection to 192.168.100.78 from 192.168.100.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:131.0) Gecko/20100101 Firefox/131.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 04 18:46:57 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:46:57 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:57 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 04 18:46:57 tomsvolumio volumio[991]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 04 18:46:57 tomsvolumio volumio[991]: info: Listing playlists Oct 04 18:46:57 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 04 18:46:57 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 04 18:46:57 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 04 18:46:57 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 04 18:46:59 tomsvolumio volumio[991]: info: Received Get System Info Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 04 18:46:59 tomsvolumio volumio[991]: info: Discovery: Getting this device information Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:46:59 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetVisibleSources Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetQueue Oct 04 18:46:59 tomsvolumio volumio[991]: info: CoreStateMachine::getQueue Oct 04 18:46:59 tomsvolumio volumio[991]: info: CorePlayQueue::getQueue Oct 04 18:47:01 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , handleBrowseUri Oct 04 18:47:01 tomsvolumio volumio[991]: info: Preload queue cleared Oct 04 18:47:01 tomsvolumio volumio[991]: info: Executing endpoint metavolumio Oct 04 18:47:01 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 04 18:47:01 tomsvolumio volumio[991]: info: Executing endpoint metavolumio Oct 04 18:47:01 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 04 18:47:03 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 04 18:47:03 tomsvolumio volumio[991]: info: Received Get System Info Oct 04 18:47:03 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 04 18:47:03 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 04 18:47:03 tomsvolumio volumio[991]: info: Discovery: Getting this device information Oct 04 18:47:03 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:47:03 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:47:03 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 04 18:47:04 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:47:04 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:04 tomsvolumio volumio[991]: info: Prefetching next song Oct 04 18:47:04 tomsvolumio volumio[991]: info: [1728060424615] ControllerTidal::prefetch Oct 04 18:47:04 tomsvolumio volumio[991]: info: Getting stream with soundQuality LOSSLESS Oct 04 18:47:04 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS" Oct 04 18:47:04 tomsvolumio volumio[991]: info: Oct 04 18:47:04 tomsvolumio volumio[991]: ---------------------------- MPD announces system playlist update Oct 04 18:47:04 tomsvolumio volumio[991]: info: Ignoring MPD Status Update Oct 04 18:47:04 tomsvolumio volumio[991]: STREAMING PROXY: Handling url /?data=tidal://song/356980315&soundQuality=LOSSLESS Oct 04 18:47:04 tomsvolumio volumio[991]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS" took 4 milliseconds Oct 04 18:47:04 tomsvolumio volumio[991]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 04 18:47:04 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 04 18:47:04 tomsvolumio volumio[991]: info: ------------------------------ 5ms Oct 04 18:47:04 tomsvolumio volumio[991]: info: sendMpdCommand consume 1 took 2 milliseconds Oct 04 18:47:04 tomsvolumio volumio[991]: info: Executing endpoint getStreamUrltidal Oct 04 18:47:04 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Oct 04 18:47:04 tomsvolumio volumio[991]: info: CALLMETHOD: music_service cd_controller getRipInfo Oct 04 18:47:04 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , getRipInfo Oct 04 18:47:05 tomsvolumio volumio[991]: info: getStreamUrl took 709 milliseconds Oct 04 18:47:05 tomsvolumio volumio[991]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiRlYzM2NjM5N2JhYjRmOTJjYzA5OThmMTM1MTA1N2Y3OC5tcDQ/0.flac?Expires=1728064025&Signature=ogXTMaLK-0U3xvEOjDEMUQ1eqChugwZ3kjWqXccxVX~JNDXFRyooJNC3nm1ZvmY5ZC-mwqzru4lYLsSmFYkJYPQ63vyT26~IXvOW2YkaPlJ1oupcDo3lhms2BUk-9Ek2-6sVpEOtEbWcgn7FWQ5U1VTbWyN4Rdd5Hx~1LTtF4NhDq1ymFh8ImK7akFYPIlqzedA44nCLTkwL6aHRYweBgCTi8anIWvg7OUQTuBp9RGkhkQGk2x2PeA0tlboVKOKLECb5dktcA6rH1m9mnsXecIHDA8lydlXvP7Kl2OJZHbSQdxvhX8w64Qy~k4LJI70TvLl4YKWkb41~D8I~HmLjWA__&Key-Pair-Id=K14LZCZ9QUI4JL Oct 04 18:47:05 tomsvolumio volumio[991]: STREAMING PROXY: Response: 200, length: 22330488 Oct 04 18:47:05 tomsvolumio kernel: hwmon hwmon1: Voltage normalised Oct 04 18:47:06 tomsvolumio volumiossh-tunnel[6322]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Oct 04 18:47:08 tomsvolumio volumio[991]: info: Oct 04 18:47:08 tomsvolumio volumio[991]: ---------------------------- MPD announces system playlist update Oct 04 18:47:08 tomsvolumio volumio[991]: info: Ignoring MPD Status Update Oct 04 18:47:08 tomsvolumio volumio[991]: info: Oct 04 18:47:08 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: player Oct 04 18:47:08 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:47:08 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:08 tomsvolumio volumio[991]: info: ------------------------------ 4ms Oct 04 18:47:08 tomsvolumio volumio[991]: info: sendMpdCommand status took 2 milliseconds Oct 04 18:47:08 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:08 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:47:08 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 04 18:47:08 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:47:08 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:47:08 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 4 Oct 04 18:47:08 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"613 Kbps","isStreaming":false,"title":"356980315&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:47:08 tomsvolumio volumio[991]: verbose: CURRENT POSITION 4 Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:47:08 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:08 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:08 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:08 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:08 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:08 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:08 tomsvolumio volumio[991]: info: ------------------------------ 89ms Oct 04 18:47:08 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:08 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:09 tomsvolumio volumio[991]: info: CoreStateMachine::startPlaybackTimer Oct 04 18:47:09 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:09 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:09 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:09 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 18:47:09 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:09 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:09 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:09 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:11 tomsvolumio volumio[991]: info: CALLMETHOD: music_service cd_controller ripCD [object Object] Oct 04 18:47:11 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , ripCD Oct 04 18:47:11 tomsvolumio volumio[991]: info: Set CD Speed to 12X Oct 04 18:47:11 tomsvolumio volumio[991]: info: Starting CD RIP TO DESTINATION: /mnt/USB/Seagate_Expansion_Drive Oct 04 18:47:13 tomsvolumio volumio[991]: STREAMING PROXY: Client dropped request, destroying Oct 04 18:47:13 tomsvolumio kernel: hwmon hwmon1: Undervoltage detected! Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 04 18:47:15 tomsvolumio volumio[991]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 04 18:47:15 tomsvolumio volumio[991]: info: Received Get System Version Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 04 18:47:15 tomsvolumio volumio[991]: info: Received Get System Info Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 04 18:47:15 tomsvolumio volumio[991]: info: Discovery: Getting this device information Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:47:15 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:15 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot disable (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot disable (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot disable (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot reset (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot disable (err = -71) Oct 04 18:47:16 tomsvolumio kernel: usb 1-1.5-port4: cannot disable (err = -71) Oct 04 18:47:16 tomsvolumio kernel: hub 1-1.5:1.0: hub_ext_port_status failed (err = -71) Oct 04 18:47:17 tomsvolumio kernel: usb 1-1-port2: over-current change #1 Oct 04 18:47:17 tomsvolumio kernel: usb 1-1.3: USB disconnect, device number 4 Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 264208 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 2, lost async page write Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 264544 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 44, lost async page write Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 6347920 op 0x1:(WRITE) flags 0x0 phys_seg 2 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 760466, lost async page write Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 760467, lost async page write Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 6555640 op 0x1:(WRITE) flags 0x0 phys_seg 3 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 786431, lost async page write Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 786432, lost async page write Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 786433, lost async page write Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 6564544 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 787544, lost async page write Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 6566000 op 0x1:(WRITE) flags 0x0 phys_seg 2 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 787726, lost async page write Oct 04 18:47:17 tomsvolumio kernel: Buffer I/O error on dev sda2, logical block 787727, lost async page write Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 6566128 op 0x1:(WRITE) flags 0x0 phys_seg 2 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 1008064992 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 1008189544 op 0x1:(WRITE) flags 0x4000 phys_seg 30 prio class 2 Oct 04 18:47:17 tomsvolumio kernel: device offline error, dev sda, sector 1008189784 op 0x1:(WRITE) flags 0x4000 phys_seg 30 prio class 2 Oct 04 18:47:17 tomsvolumio volumio[991]: info: Partition removed: {"syspath":"/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","DEVLINKS":"/dev/disk/by-partlabel/Microsoft\\x20reserved\\x20partition /dev/disk/by-path/platform-3f980000.usb-usb-0:1.3:1.0-scsi-0:0:0:0-part1 /dev/disk/by-id/ata-ST4000DM004-2CV104_ZFN1VCVY-part1 /dev/disk/by-id/wwn-0x5000c500b47a9681-part1 /dev/disk/by-partuuid/8d613e12-6084-4e26-8bc9-e622091d5184","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"26","ID_ATA":"1","ID_ATA_DOWNLOAD_MICROCODE":"1","ID_ATA_FEATURE_SET_HPA":"1","ID_ATA_FEATURE_SET_HPA_ENABLED":"1","ID_ATA_FEATURE_SET_PM":"1","ID_ATA_FEATURE_SET_PM_ENABLED":"1","ID_ATA_FEATURE_SET_PUIS":"1","ID_ATA_FEATURE_SET_PUIS_ENABLED":"0","ID_ATA_FEATURE_SET_SECURITY":"1","ID_ATA_FEATURE_SET_SECURITY_ENABLED":"0","ID_ATA_FEATURE_SET_SECURITY_ENHANCED_ERASE_UNIT_MIN":"492","ID_ATA_FEATURE_SET_SECURITY_ERASE_UNIT_MIN":"492","ID_ATA_FEATURE_SET_SMART":"1","ID_ATA_FEATURE_SET_SMART_ENABLED":"1","ID_ATA_ROTATION_RATE_RPM":"5425","ID_ATA_SATA":"1","ID_ATA_SATA_SIGNAL_RATE_GEN1":"1","ID_ATA_SATA_SIGNAL_RATE_GEN2":"1","ID_ATA_WRITE_CACHE":"1","ID_ATA_WRITE_CACHE_ENABLED":"1","ID_BUS":"ata","ID_MODEL":"ST4000DM004-2CV104","ID_MODEL_ENC":"ST4000DM004-2CV104\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NAME":"Microsoft\\x20reserved\\x20partition","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"34","ID_PART_ENTRY_SCHEME":"gpt","ID_PART_ENTRY_SIZE":"262144","ID_PART_ENTRY_TYPE":"e3c9e316-0b5c-4db8-817d-f92df00215ae","ID_PART_ENTRY_UUID":"8d613e12-6084-4e26-8bc9-e622091d5184","ID_PART_TABLE_TYPE":"gpt","ID_PART_TABLE_UUID":"8a6319e9-e981-475f-baa3-d9a5afd52290","ID_PATH":"platform-3f980000.usb-usb-0:1.3:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-3f980000_usb-usb-0_1_3_1_0-scsi-0_0_0_0","ID_REVISION":"0001","ID_SERIAL":"ST4000DM004-2CV104_ZFN1VCVY","ID_SERIAL_SHORT":"ZFN1VCVY","ID_TYPE":"disk","ID_WWN":"0x5000c500b47a9681","ID_WWN_WITH_EXTENSION":"0x5000c500b47a9681","MAJOR":"8","MINOR":"1","PARTN":"1","PARTNAME":"Microsoft reserved partition","SEQNUM":"2049","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"13009606"} Oct 04 18:47:17 tomsvolumio volumio[991]: error: Cannot associate FS Label, not mounting Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot disable (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot disable (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot disable (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot reset (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: Cannot enable. Maybe the USB cable is bad? Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot disable (err = -71) Oct 04 18:47:18 tomsvolumio kernel: usb 1-1.5-port2: cannot disable (err = -71) Oct 04 18:47:18 tomsvolumio kernel: hub 1-1.5:1.0: hub_ext_port_status failed (err = -71) Oct 04 18:47:18 tomsvolumio kernel: hub 1-1.5:1.0: hub_ext_port_status failed (err = -71) Oct 04 18:47:18 tomsvolumio volumio[991]: info: Partition removed: {"syspath":"/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda2","ACTION":"remove","DEVLINKS":"/dev/disk/by-uuid/18B62C49B62C29A8 /dev/disk/by-id/ata-ST4000DM004-2CV104_ZFN1VCVY-part2 /dev/disk/by-partuuid/3782cf88-cf4e-4ad5-a33f-00dadb2544ae /dev/disk/by-label/Seagate\\x20Expansion\\x20Drive /dev/disk/by-path/platform-3f980000.usb-usb-0:1.3:1.0-scsi-0:0:0:0-part2 /dev/disk/by-partlabel/Basic\\x20data\\x20partition /dev/disk/by-id/wwn-0x5000c500b47a9681-part2","DEVNAME":"/dev/sda2","DEVPATH":"/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda2","DEVTYPE":"partition","DISKSEQ":"26","ID_ATA":"1","ID_ATA_DOWNLOAD_MICROCODE":"1","ID_ATA_FEATURE_SET_HPA":"1","ID_ATA_FEATURE_SET_HPA_ENABLED":"1","ID_ATA_FEATURE_SET_PM":"1","ID_ATA_FEATURE_SET_PM_ENABLED":"1","ID_ATA_FEATURE_SET_PUIS":"1","ID_ATA_FEATURE_SET_PUIS_ENABLED":"0","ID_ATA_FEATURE_SET_SECURITY":"1","ID_ATA_FEATURE_SET_SECURITY_ENABLED":"0","ID_ATA_FEATURE_SET_SECURITY_ENHANCED_ERASE_UNIT_MIN":"492","ID_ATA_FEATURE_SET_SECURITY_ERASE_UNIT_MIN":"492","ID_ATA_FEATURE_SET_SMART":"1","ID_ATA_FEATURE_SET_SMART_ENABLED":"1","ID_ATA_ROTATION_RATE_RPM":"5425","ID_ATA_SATA":"1","ID_ATA_SATA_SIGNAL_RATE_GEN1":"1","ID_ATA_SATA_SIGNAL_RATE_GEN2":"1","ID_ATA_WRITE_CACHE":"1","ID_ATA_WRITE_CACHE_ENABLED":"1","ID_BUS":"ata","ID_FS_LABEL":"Seagate_Expansion_Drive","ID_FS_LABEL_ENC":"Seagate\\x20Expansion\\x20Drive","ID_FS_TYPE":"ntfs","ID_FS_USAGE":"filesystem","ID_FS_UUID":"18B62C49B62C29A8","ID_FS_UUID_ENC":"18B62C49B62C29A8","ID_MODEL":"ST4000DM004-2CV104","ID_MODEL_ENC":"ST4000DM004-2CV104\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NAME":"Basic\\x20data\\x20partition","ID_PART_ENTRY_NUMBER":"2","ID_PART_ENTRY_OFFSET":"264192","ID_PART_ENTRY_SCHEME":"gpt","ID_PART_ENTRY_SIZE":"7813771264","ID_PART_ENTRY_TYPE":"ebd0a0a2-b9e5-4433-87c0-68b6b72699c7","ID_PART_ENTRY_UUID":"3782cf88-cf4e-4ad5-a33f-00dadb2544ae","ID_PART_TABLE_TYPE":"atari","ID_PART_TABLE_UUID":"8a6319e9-e981-475f-baa3-d9a5afd52290","ID_PATH":"platform-3f980000.usb-usb-0:1.3:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-3f980000_usb-usb-0_1_3_1_0-scsi-0_0_0_0","ID_REVISION":"0001","ID_SERIAL":"ST4000DM004-2CV104_ZFN1VCVY","ID_SERIAL_SHORT":"ZFN1VCVY","ID_TYPE":"disk","ID_WWN":"0x5000c500b47a9681","ID_WWN_WITH_EXTENSION":"0x5000c500b47a9681","MAJOR":"8","MINOR":"2","PARTN":"2","PARTNAME":"Basic data partition","SEQNUM":"2050","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"13010515"} Oct 04 18:47:18 tomsvolumio sudo[7185]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda2 Oct 04 18:47:18 tomsvolumio sudo[7185]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:47:18 tomsvolumio kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache Oct 04 18:47:18 tomsvolumio kernel: sd 0:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK Oct 04 18:47:18 tomsvolumio ntfs-3g[1052]: Unmounting /dev/sda2 (Seagate Expansion Drive) Oct 04 18:47:18 tomsvolumio sudo[7185]: pam_unix(sudo:session): session closed for user root Oct 04 18:47:18 tomsvolumio volumio[991]: umount: /media/Seagate_Expansion_Drive: target is busy. Oct 04 18:47:18 tomsvolumio volumio[991]: error: Failed to umount Seagate_Expansion_Drive: Error: Command failed: /usr/bin/sudo /bin/umount -f "/dev/sda2" Oct 04 18:47:18 tomsvolumio volumio[991]: umount: /media/Seagate_Expansion_Drive: target is busy. Oct 04 18:47:18 tomsvolumio ntfs-3g[1052]: Failed to sync device /dev/sda2: Input/output error Oct 04 18:47:18 tomsvolumio ntfs-3g[1052]: Failed to fsync device /dev/sda2: Input/output error Oct 04 18:47:18 tomsvolumio ntfs-3g[1052]: Failed to close volume /dev/sda2: Device or resource busy Oct 04 18:47:18 tomsvolumio volumio[991]: info: Executing endpoint cdPostRip Oct 04 18:47:18 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , notifyPostRip Oct 04 18:47:18 tomsvolumio volumio[991]: info: CD RIP Terminated Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: new high-speed USB device number 8 using dwc_otg Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: New USB device found, idVendor=0bc2, idProduct=3323, bcdDevice= 1.00 Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: New USB device strings: Mfr=2, Product=3, SerialNumber=1 Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: Product: Expansion+ Desk Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: Manufacturer: Seagate Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: SerialNumber: NAAC037H Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: The driver for the USB controller dwc_otg_hcd does not support scatter-gather which is Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.3: required by the UAS driver. Please try an other USB controller if you wish to use UAS. Oct 04 18:47:19 tomsvolumio kernel: usb-storage 1-1.3:1.0: USB Mass Storage device detected Oct 04 18:47:19 tomsvolumio kernel: scsi host3: usb-storage 1-1.3:1.0 Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.5: USB disconnect, device number 5 Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.5.2: USB disconnect, device number 6 Oct 04 18:47:19 tomsvolumio volumio[991]: info: Set CD Speed to 4X Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:19 tomsvolumio volumio[991]: info: Oct 04 18:47:19 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: update Oct 04 18:47:19 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:19 tomsvolumio kernel: usb 1-1.5.4: USB disconnect, device number 7 Oct 04 18:47:19 tomsvolumio volumio[991]: info: Updating MPD DB after CD rip Oct 04 18:47:19 tomsvolumio volumio[991]: info: Syncing changes to disk Oct 04 18:47:19 tomsvolumio volumio[991]: info: Cleaning abcde folders after CD rip Oct 04 18:47:19 tomsvolumio volumio[991]: error: Cannot Clean after rip: Error: Command failed: /bin/rm -rf /mnt/USB/Seagate_Expansion_Drive/abcde.* Oct 04 18:47:19 tomsvolumio volumio[991]: /bin/rm: cannot remove '/mnt/USB/Seagate_Expansion_Drive/abcde.*': Transport endpoint is not connected Oct 04 18:47:19 tomsvolumio volumio[991]: info: MPD Database updated - AlbumList cache refreshed Oct 04 18:47:19 tomsvolumio volumio[991]: info: Oct 04 18:47:19 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: database Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:19 tomsvolumio volumio[991]: info: Oct 04 18:47:19 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: update Oct 04 18:47:19 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:19 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand status took 65 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand status took 60 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:19 tomsvolumio volumio[991]: info: Command Router : Notfying DB Updatefalse Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::Close All Modals sent Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand status took 256 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand status took 253 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand status took 251 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 137 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:19 tomsvolumio volumio[991]: info: Command Router : Notfying DB Updatefalse Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::Close All Modals sent Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:47:19 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10684,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"444 Kbps","isStreaming":false,"title":"356980315&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: CURRENT POSITION 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:47:19 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:19 tomsvolumio volumio[991]: info: ------------------------------ 486ms Oct 04 18:47:19 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:19 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 163 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 163 milliseconds Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:47:19 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10684,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"444 Kbps","isStreaming":false,"title":"356980315&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: CURRENT POSITION 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:47:19 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:19 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10684,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"444 Kbps","isStreaming":false,"title":"356980315&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:47:19 tomsvolumio volumio[991]: verbose: CURRENT POSITION 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:47:19 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:19 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:19 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:20 tomsvolumio volumio[991]: info: ------------------------------ 636ms Oct 04 18:47:20 tomsvolumio volumio[991]: info: ------------------------------ 635ms Oct 04 18:47:20 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:20 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:20 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:20 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:20 tomsvolumio kernel: scsi 3:0:0:0: Direct-Access Seagate Expansion+ Desk 9401 PQ: 0 ANSI: 6 Oct 04 18:47:20 tomsvolumio kernel: sd 3:0:0:0: Attached scsi generic sg0 type 0 Oct 04 18:47:20 tomsvolumio kernel: sd 3:0:0:0: [sdb] Spinning up disk... Oct 04 18:47:23 tomsvolumio kernel: ...ready Oct 04 18:47:23 tomsvolumio kernel: sd 3:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16). Oct 04 18:47:23 tomsvolumio kernel: sd 3:0:0:0: [sdb] 7814037167 512-byte logical blocks: (4.00 TB/3.64 TiB) Oct 04 18:47:23 tomsvolumio kernel: sd 3:0:0:0: [sdb] Write Protect is off Oct 04 18:47:23 tomsvolumio kernel: sd 3:0:0:0: [sdb] Mode Sense: 4f 00 00 00 Oct 04 18:47:23 tomsvolumio kernel: sd 3:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Oct 04 18:47:23 tomsvolumio kernel: sdb: sdb1 sdb2 Oct 04 18:47:23 tomsvolumio kernel: sd 3:0:0:0: [sdb] Attached SCSI disk Oct 04 18:47:23 tomsvolumio volumio[991]: info: Scanning removed location : "USB/Seagate_Expansion_Drive" Oct 04 18:47:23 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:23 tomsvolumio volumio[991]: info: Oct 04 18:47:23 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: update Oct 04 18:47:23 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:47:23 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:23 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:23 tomsvolumio volumio[991]: info: Oct 04 18:47:23 tomsvolumio volumio[991]: ---------------------------- MPD announces state update: update Oct 04 18:47:23 tomsvolumio volumio[991]: info: ControllerMpd::getState Oct 04 18:47:23 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Oct 04 18:47:23 tomsvolumio volumio[991]: info: sendMpdCommand status took 13 milliseconds Oct 04 18:47:23 tomsvolumio volumio[991]: info: sendMpdCommand status took 8 milliseconds Oct 04 18:47:23 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:24 tomsvolumio volumio[991]: info: Command Router : Notfying DB Updatefalse Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreCommandRouter::Close All Modals sent Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:47:24 tomsvolumio volumio[991]: info: sendMpdCommand status took 147 milliseconds Oct 04 18:47:24 tomsvolumio volumio[991]: info: sendMpdCommand status took 145 milliseconds Oct 04 18:47:24 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:24 tomsvolumio volumio[991]: info: Command Router : Notfying DB Updatefalse Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreCommandRouter::Close All Modals sent Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: ControllerMpd::parseState Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:47:24 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:47:24 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":15169,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"629 Kbps","isStreaming":false,"title":"356980315&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:47:24 tomsvolumio volumio[991]: verbose: CURRENT POSITION 5 Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:47:24 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:24 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:24 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:24 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:24 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:24 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:24 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:24 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:24 tomsvolumio volumio[991]: info: ------------------------------ 330ms Oct 04 18:47:24 tomsvolumio volumio[991]: info: Mounting Device Seagate_Expansion_Drive Oct 04 18:47:24 tomsvolumio volumio[991]: /bin/mkdir: cannot create directory ‘/mnt/USB/Seagate_Expansion_Drive’: File exists Oct 04 18:47:24 tomsvolumio volumio[991]: error: Failed to create folder Error: Command failed: /bin/mkdir -m 777 "/mnt/USB/Seagate_Expansion_Drive" Oct 04 18:47:24 tomsvolumio volumio[991]: /bin/mkdir: cannot create directory ‘/mnt/USB/Seagate_Expansion_Drive’: File exists Oct 04 18:47:24 tomsvolumio sudo[7242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb2 /mnt/USB/Seagate_Expansion_Drive -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 04 18:47:24 tomsvolumio sudo[7242]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:47:27 tomsvolumio sudo[7242]: pam_unix(sudo:session): session closed for user root Oct 04 18:47:27 tomsvolumio volumio[991]: ntfs-3g-mount: failed to access mountpoint /media/Seagate_Expansion_Drive: Transport endpoint is not connected Oct 04 18:47:27 tomsvolumio volumio[991]: error: Failed to mount Seagate_Expansion_Drive: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sdb2" "/mnt/USB/Seagate_Expansion_Drive" -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Oct 04 18:47:27 tomsvolumio volumio[991]: ntfs-3g-mount: failed to access mountpoint /media/Seagate_Expansion_Drive: Transport endpoint is not connected Oct 04 18:47:27 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:27 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:27 tomsvolumio volumio[991]: info: sendMpdCommand playlistinfo took 3863 milliseconds Oct 04 18:47:27 tomsvolumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Oct 04 18:47:27 tomsvolumio volumio[991]: info: ControllerMpd::pushState Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreCommandRouter::servicePushState Oct 04 18:47:27 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:27 tomsvolumio volumio[991]: verbose: STATE SERVICE {"status":"play","position":0,"seek":15169,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"629 Kbps","isStreaming":false,"title":"356980315&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/356980315&soundQuality=LOSSLESS","trackType":"tidal"} Oct 04 18:47:27 tomsvolumio volumio[991]: verbose: CURRENT POSITION 5 Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreStateMachine::syncState stateService play Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreStateMachine::syncState currentStatus play Oct 04 18:47:27 tomsvolumio volumio[991]: info: Received an update from plugin. extracting info from payload Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:27 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:27 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:27 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreStateMachine::pushState Oct 04 18:47:27 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:27 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioPushState Oct 04 18:47:27 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output update for this device Oct 04 18:47:28 tomsvolumio volumio[991]: info: MRS: Pushing multiroomSync output Oct 04 18:47:28 tomsvolumio volumio[991]: info: ------------------------------ 4124ms Oct 04 18:47:28 tomsvolumio volumio[991]: error: Cannot associate FS Label, not mounting Oct 04 18:47:28 tomsvolumio volumio[991]: info: CD Rip Successfully started Oct 04 18:47:28 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:28 tomsvolumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 04 18:47:30 tomsvolumio kernel: hwmon hwmon1: Voltage normalised Oct 04 18:47:44 tomsvolumio sudo[7250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 04 18:47:44 tomsvolumio sudo[7250]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:47:44 tomsvolumio sudo[7250]: pam_unix(sudo:session): session closed for user root Oct 04 18:47:44 tomsvolumio sudo[7252]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 04 18:47:44 tomsvolumio sudo[7252]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:47:44 tomsvolumio sudo[7252]: pam_unix(sudo:session): session closed for user root Oct 04 18:47:44 tomsvolumio volumio[991]: verbose: New Socket.io Connection to 192.168.100.78 from 192.168.100.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:131.0) Gecko/20100101 Firefox/131.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 04 18:47:44 tomsvolumio kernel: hwmon hwmon1: Undervoltage detected! Oct 04 18:47:44 tomsvolumio sudo[7256]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 04 18:47:44 tomsvolumio sudo[7256]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:47:44 tomsvolumio sudo[7256]: pam_unix(sudo:session): session closed for user root Oct 04 18:47:44 tomsvolumio sudo[7259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 04 18:47:44 tomsvolumio sudo[7259]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 04 18:47:45 tomsvolumio sudo[7259]: pam_unix(sudo:session): session closed for user root Oct 04 18:47:45 tomsvolumio volumio[991]: verbose: New Socket.io Connection to 192.168.100.78 from 192.168.100.44 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:131.0) Gecko/20100101 Firefox/131.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 04 18:47:45 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:47:45 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:45 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 04 18:47:45 tomsvolumio volumio[991]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 04 18:47:45 tomsvolumio volumio[991]: info: Listing playlists Oct 04 18:47:45 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 04 18:47:45 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 04 18:47:45 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 04 18:47:45 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 04 18:47:46 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 04 18:47:46 tomsvolumio volumio[991]: info: Received Get System Info Oct 04 18:47:46 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 04 18:47:46 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 04 18:47:46 tomsvolumio volumio[991]: info: Discovery: Getting this device information Oct 04 18:47:46 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:47:46 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:46 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 04 18:47:46 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 04 18:47:47 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetVisibleSources Oct 04 18:47:47 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 04 18:47:47 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetQueue Oct 04 18:47:47 tomsvolumio volumio[991]: info: CoreStateMachine::getQueue Oct 04 18:47:47 tomsvolumio volumio[991]: info: CorePlayQueue::getQueue Oct 04 18:47:49 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , handleBrowseUri Oct 04 18:47:49 tomsvolumio volumio[991]: info: Preload queue cleared Oct 04 18:47:49 tomsvolumio volumio[991]: info: Executing endpoint metavolumio Oct 04 18:47:49 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 04 18:47:49 tomsvolumio volumio[991]: info: Executing endpoint metavolumio Oct 04 18:47:49 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 04 18:47:50 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 04 18:47:50 tomsvolumio volumio[991]: info: Received Get System Info Oct 04 18:47:50 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 04 18:47:50 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 04 18:47:50 tomsvolumio volumio[991]: info: Discovery: Getting this device information Oct 04 18:47:50 tomsvolumio volumio[991]: info: CoreCommandRouter::volumioGetState Oct 04 18:47:50 tomsvolumio volumio[991]: info: CorePlayQueue::getTrack 5 Oct 04 18:47:50 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 04 18:47:51 tomsvolumio kernel: hwmon hwmon1: Voltage normalised Oct 04 18:47:52 tomsvolumio volumio[991]: info: CALLMETHOD: music_service cd_controller getRipInfo Oct 04 18:47:52 tomsvolumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: cd_controller , getRipInfo Oct 04 18:47:52 tomsvolumio volumio[991]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 04 18:47:52 tomsvolumio volumio[991]: Error: ENOTCONN: socket is not connected, lstat '/mnt/USB/Seagate_Expansion_Drive' Oct 04 18:47:52 tomsvolumio volumio[991]: at Object.lstatSync (fs.js:1077:3) Oct 04 18:47:52 tomsvolumio volumio[991]: at Object.lstatSync (/volumio/node_modules/graceful-fs/polyfills.js:308:16) Oct 04 18:47:52 tomsvolumio volumio[991]: at /myvolumio/plugins/music_service/cd_controller/cd_controller_real:1:14222 Oct 04 18:47:52 tomsvolumio volumio[991]: at go$readdir$cb (/volumio/node_modules/graceful-fs/graceful-fs.js:195:14) Oct 04 18:47:52 tomsvolumio volumio[991]: at FSReqCallback.oncomplete (fs.js:171:23) { Oct 04 18:47:52 tomsvolumio volumio[991]: errno: -107, Oct 04 18:47:52 tomsvolumio volumio[991]: syscall: 'lstat', Oct 04 18:47:52 tomsvolumio volumio[991]: code: 'ENOTCONN', Oct 04 18:47:52 tomsvolumio volumio[991]: path: '/mnt/USB/Seagate_Expansion_Drive' Oct 04 18:47:52 tomsvolumio volumio[991]: } Oct 04 18:47:52 tomsvolumio volumio[991]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 04 18:47:52 tomsvolumio sudo[7272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-04 18:46 Oct 04 18:47:52 tomsvolumio sudo[7272]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"