Feb 07 18:11:00 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:03 volumio volumio[13969]: info: CALLMETHOD: music_service volusonic savePluginOptions [object Object] Feb 07 18:11:03 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volusonic , savePluginOptions Feb 07 18:11:03 volumio volumio[13969]: debug: API:printToastMessage Feb 07 18:11:03 volumio volumio[13969]: info: CoreCommandRouter::volumioClearQueue Feb 07 18:11:03 volumio volumio[13969]: info: CoreStateMachine::ClearQueue Feb 07 18:11:03 volumio volumio[13969]: info: CoreStateMachine::stop Feb 07 18:11:03 volumio volumio[13969]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 18:11:03 volumio volumio[13969]: info: CorePlayQueue::clearPlayQueue Feb 07 18:11:03 volumio volumio[13969]: info: CorePlayQueue::saveQueue Feb 07 18:11:03 volumio volumio[13969]: debug: CoreStateMachine::pushEmptyState Feb 07 18:11:03 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:03 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:03 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:03 volumio volumio[13969]: info: CoreCommandRouter::volumioPushQueue Feb 07 18:11:03 volumio volumio[13969]: debug: API:pushQueue Feb 07 18:11:05 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:10 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 07 18:11:10 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 07 18:11:15 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:17 volumio volumio[13969]: info: CoreCommandRouter::volumioGetState Feb 07 18:11:17 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:17 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:19 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volusonic , handleBrowseUri Feb 07 18:11:19 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:20 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:23 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volusonic , handleBrowseUri Feb 07 18:11:23 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:23 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:23 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/cxyjfdfVU5eATiMvIIDiXf Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/79g1vRdQrzc2hNgcUHWHHn Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/vQZSUcj1A8ISYONP0jF4e6 Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/Bwtv1aYoDA1gNjMmeO5GtB Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/wWdiwqKqXQpTqunctGJCSR Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/oznLJ4eVZ7OncrezVDlSJD Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/vhUtVZlSdb8Tx7LDaaTcm1 Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/pT66rTTrtRJImUQPyoaLXL Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/z4oQ465tJCYR6hKJ0e4CwP Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/Fe4gQfQJzRb7DwsCt4kAdx Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/DFVkNhhgFvZqfWCJ0bksG9 Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/6Qr13Lp1XHVPxr7L8RBCzl Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/DkZ6vd5rWy1Ir2p3L7jdEc Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/lXwhOnc0ZaPkRsooFIX6Gu Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/QOqLXLi9Lv11jNe1fiD5vP Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/eSbz44OhzNL3x3qnC18gdG Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/2YJloR2YDe7p8ZVo1bFzP7 Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/abSEGEKTgAGU9osV9QefsT Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/hDgXcAcYfVGiLRFbzZYplC Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/GNkERxnuPfSgPvEaVA9jsC Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/s15Z6b9V33WrLbJ5AraxWe Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/CosjkUjhqt8C3dwu444uHd Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/aRNfwrEhpTKaTqr5luj3eO Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/j6gsvMP67UDq6gviYDPdCt Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/JEFByGnmS02lKMBKhUlE9U Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/ybja42giy8sPohD0qNxTwS Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/r3DkuwutjT0qz5pgWkCfkD Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/K1KBUH3Bq04V3lVUQKg7s7 Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/nHQ2tkpYRX86QbJlRgfcIb Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/9Uw9D5emMq7Rd4nb9yA11q Feb 07 18:11:23 volumio volumio[13969]: info: Preloading song: volusonic/track/KaJG4Q3E6XgGHtFsAbvib1 Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/cxyjfdfVU5eATiMvIIDiXf in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/79g1vRdQrzc2hNgcUHWHHn in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/vQZSUcj1A8ISYONP0jF4e6 in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/Bwtv1aYoDA1gNjMmeO5GtB in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/wWdiwqKqXQpTqunctGJCSR in service volusonic Feb 07 18:11:23 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/wWdiwqKqXQpTqunctGJCSR from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/oznLJ4eVZ7OncrezVDlSJD in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/vhUtVZlSdb8Tx7LDaaTcm1 in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/pT66rTTrtRJImUQPyoaLXL in service volusonic Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/z4oQ465tJCYR6hKJ0e4CwP in service volusonic Feb 07 18:11:23 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/z4oQ465tJCYR6hKJ0e4CwP from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/Fe4gQfQJzRb7DwsCt4kAdx in service volusonic Feb 07 18:11:23 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/Fe4gQfQJzRb7DwsCt4kAdx from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/DFVkNhhgFvZqfWCJ0bksG9 in service volusonic Feb 07 18:11:23 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/DFVkNhhgFvZqfWCJ0bksG9 from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:23 volumio volumio[13969]: info: Exploding uri volusonic/track/6Qr13Lp1XHVPxr7L8RBCzl in service volusonic Feb 07 18:11:23 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/6Qr13Lp1XHVPxr7L8RBCzl from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/DkZ6vd5rWy1Ir2p3L7jdEc in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/lXwhOnc0ZaPkRsooFIX6Gu in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/QOqLXLi9Lv11jNe1fiD5vP in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/eSbz44OhzNL3x3qnC18gdG in service volusonic Feb 07 18:11:24 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/eSbz44OhzNL3x3qnC18gdG from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/2YJloR2YDe7p8ZVo1bFzP7 in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/abSEGEKTgAGU9osV9QefsT in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/hDgXcAcYfVGiLRFbzZYplC in service volusonic Feb 07 18:11:24 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/hDgXcAcYfVGiLRFbzZYplC from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/GNkERxnuPfSgPvEaVA9jsC in service volusonic Feb 07 18:11:24 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/GNkERxnuPfSgPvEaVA9jsC from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/s15Z6b9V33WrLbJ5AraxWe in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/CosjkUjhqt8C3dwu444uHd in service volusonic Feb 07 18:11:24 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/CosjkUjhqt8C3dwu444uHd from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/aRNfwrEhpTKaTqr5luj3eO in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/j6gsvMP67UDq6gviYDPdCt in service volusonic Feb 07 18:11:24 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/j6gsvMP67UDq6gviYDPdCt from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/JEFByGnmS02lKMBKhUlE9U in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/ybja42giy8sPohD0qNxTwS in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/r3DkuwutjT0qz5pgWkCfkD in service volusonic Feb 07 18:11:24 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/r3DkuwutjT0qz5pgWkCfkD from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/K1KBUH3Bq04V3lVUQKg7s7 in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/nHQ2tkpYRX86QbJlRgfcIb in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/9Uw9D5emMq7Rd4nb9yA11q in service volusonic Feb 07 18:11:24 volumio volumio[13969]: info: Exploding uri volusonic/track/KaJG4Q3E6XgGHtFsAbvib1 in service volusonic Feb 07 18:11:25 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:25 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volusonic , handleBrowseUri Feb 07 18:11:26 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/uN8gvXmsghbPu55kQ6TxcN Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/QX2sdNpULMfBQXfelpQulA Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/TkpgeqwT0zwr2B0b6bCNAI Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/Tx4KAoWkZXnK1F6JFcWV1B Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/fGtuK8ChQoBENkvYaVmZ2C Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/Q6vJufyt6iHlMsIZ4ic4SH Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/11zPManBq6qPgNTvJKQUWB Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/8Sh1IYHf3oLPemNtHSyWuQ Feb 07 18:11:26 volumio volumio[13969]: info: Preloading song: volusonic/track/robC940n0EDwNoHCnEZFtY Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/uN8gvXmsghbPu55kQ6TxcN in service volusonic Feb 07 18:11:26 volumio volumio[13969]: info: No valid Plugin REST Endpoint Feb 07 18:11:26 volumio volumio[13969]: info: No valid Plugin REST Endpoint Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/QX2sdNpULMfBQXfelpQulA in service volusonic Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/TkpgeqwT0zwr2B0b6bCNAI in service volusonic Feb 07 18:11:26 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/TkpgeqwT0zwr2B0b6bCNAI from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/Tx4KAoWkZXnK1F6JFcWV1B in service volusonic Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/fGtuK8ChQoBENkvYaVmZ2C in service volusonic Feb 07 18:11:26 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/fGtuK8ChQoBENkvYaVmZ2C from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/Q6vJufyt6iHlMsIZ4ic4SH in service volusonic Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/11zPManBq6qPgNTvJKQUWB in service volusonic Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/8Sh1IYHf3oLPemNtHSyWuQ in service volusonic Feb 07 18:11:26 volumio volumio[13969]: info: Exploding uri volusonic/track/robC940n0EDwNoHCnEZFtY in service volusonic Feb 07 18:11:26 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/robC940n0EDwNoHCnEZFtY from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:27 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::ClearQueue Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::stop Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::clearPlayQueue Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::saveQueue Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushQueue Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushQueue Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::addQueueItems Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::addQueueItems Feb 07 18:11:27 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/uN8gvXmsghbPu55kQ6TxcN Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/uN8gvXmsghbPu55kQ6TxcN in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushQueue Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushQueue Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::saveQueue Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::updateTrackBlock Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrackBlock Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPlay Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::play index 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::addQueueItems Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::addQueueItems Feb 07 18:11:27 volumio volumio[13969]: info: Preload queue cleared Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/QX2sdNpULMfBQXfelpQulA Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/QX2sdNpULMfBQXfelpQulA in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/TkpgeqwT0zwr2B0b6bCNAI Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/TkpgeqwT0zwr2B0b6bCNAI in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/Tx4KAoWkZXnK1F6JFcWV1B Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/Tx4KAoWkZXnK1F6JFcWV1B in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/fGtuK8ChQoBENkvYaVmZ2C Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/fGtuK8ChQoBENkvYaVmZ2C in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/Q6vJufyt6iHlMsIZ4ic4SH Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/Q6vJufyt6iHlMsIZ4ic4SH in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/11zPManBq6qPgNTvJKQUWB Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/11zPManBq6qPgNTvJKQUWB in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/8Sh1IYHf3oLPemNtHSyWuQ Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/8Sh1IYHf3oLPemNtHSyWuQ in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: Adding Item to queue: volusonic/track/robC940n0EDwNoHCnEZFtY Feb 07 18:11:27 volumio volumio[13969]: info: Exploding uri volusonic/track/robC940n0EDwNoHCnEZFtY in service volusonic Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::stop Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::play index undefined Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::startPlaybackTimer Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: [1770484287490] ControllerVolusonic::clearAddPlayTrack Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand stop Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand stop took 10 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand clear Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand clear took 2 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic" Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: error: updateQueue error: null Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 4ms Feb 07 18:11:27 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/TkpgeqwT0zwr2B0b6bCNAI from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:27 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/fGtuK8ChQoBENkvYaVmZ2C from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:27 volumio volumio[13969]: error: Commandrouter: Cannot explode uri volusonic/track/robC940n0EDwNoHCnEZFtY from service volusonic: Error: explodeUri volusonic/track Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushQueue Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushQueue Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::saveQueue Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::updateTrackBlock Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrackBlock Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic" Feb 07 18:11:27 volumio volumio[13969]: error: updateQueue error: null Feb 07 18:11:27 volumio volumio[13969]: error: updateQueue error: null Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 36ms Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 35ms Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand add "http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic" took 2 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand play Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 3ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand play took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 3ms Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 3ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 1 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: info: [1770484287547] ControllerVolusonic::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:27 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::syncState stateService play Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus stop Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: [1770484287563] ControllerVolusonic: MPD player state update Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 4 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 7 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 5 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 5 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 4 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 15ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 9 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: [1770484287580] ControllerVolusonic::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":321,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:27 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::syncState stateService play Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus play Feb 07 18:11:27 volumio volumio[13969]: info: Received an update from plugin. extracting info from payload Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:27 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:27 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 31ms Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 37ms Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 37ms Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 35ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 24 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 36ms Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioGetQueue Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::getQueue Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getQueue Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: [1770484287612] ControllerVolusonic: MPD player state update Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces system playlist update Feb 07 18:11:27 volumio volumio[13969]: info: Ignoring MPD Status Update Feb 07 18:11:27 volumio volumio[13969]: info: Feb 07 18:11:27 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 6 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 6ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 4 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 3ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 2ms Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: [1770484287624] ControllerVolusonic::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: verbose: STATE SERVICE {"status":"play","position":0,"seek":858,"duration":321,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1310 Kbps","isStreaming":false,"title":"Can I Have You for Myself?","artist":"By Storm","album":"My Ghosts Go Ghost","uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:27 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::syncState stateService play Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus play Feb 07 18:11:27 volumio volumio[13969]: info: Received an update from plugin. extracting info from payload Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:27 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:27 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:27 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:27 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:27 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:27 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:27 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 28ms Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 25ms Feb 07 18:11:27 volumio volumio[13969]: info: ------------------------------ 24ms Feb 07 18:11:30 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:30 volumio volumio[13969]: info: CoreCommandRouter::volumioGetState Feb 07 18:11:30 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:30 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::volumioPause Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::pause Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::stPlaybackTimer Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::servicePause Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::servicePause Feb 07 18:11:32 volumio volumio[13969]: info: [1770484292187] ControllerVolusonic::pause Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::pause Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand pause Feb 07 18:11:32 volumio volumio[13969]: info: [1770484292189] ControllerVolusonic: MPD player state update Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:32 volumio volumio[13969]: info: Feb 07 18:11:32 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand pause took 2 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:32 volumio volumio[13969]: info: Feb 07 18:11:32 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:32 volumio volumio[13969]: info: Feb 07 18:11:32 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand status took 7 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand status took 6 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand status took 5 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand status took 4 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:32 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:32 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: [1770484292204] ControllerVolusonic::pushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5485,"duration":321,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1296 Kbps","isStreaming":false,"title":"Can I Have You for Myself?","artist":"By Storm","album":"My Ghosts Go Ghost","uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:32 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::syncState stateService pause Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus pause Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:32 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:32 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::stPlaybackTimer Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:32 volumio volumio[13969]: info: [1770484292220] ControllerVolusonic::pushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5485,"duration":321,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1296 Kbps","isStreaming":false,"title":"Can I Have You for Myself?","artist":"By Storm","album":"My Ghosts Go Ghost","uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:32 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::syncState stateService pause Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus pause Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:32 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:32 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreStateMachine::stPlaybackTimer Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:32 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:32 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:32 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:32 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:32 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:32 volumio volumio[13969]: info: ------------------------------ 43ms Feb 07 18:11:32 volumio volumio[13969]: info: ------------------------------ 42ms Feb 07 18:11:32 volumio volumio[13969]: info: ------------------------------ 41ms Feb 07 18:11:35 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:40 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:45 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:48 volumio volumio[13969]: debug: No callbacks for volumiosetvolume Feb 07 18:11:48 volumio volumio[13969]: info: VolumeController::SetAlsaVolume44 Feb 07 18:11:48 volumio volumio[13969]: debug: No callbacks for volumioupdatevolume Feb 07 18:11:48 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:48 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:48 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:48 volumio volumio[13969]: info: Feb 07 18:11:48 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:48 volumio volumio[13969]: info: Feb 07 18:11:48 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:48 volumio volumio[13969]: info: Feb 07 18:11:48 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:48 volumio volumio[13969]: info: ------------------------------ 11ms Feb 07 18:11:48 volumio volumio[13969]: info: ------------------------------ 10ms Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:48 volumio volumio[13969]: info: ------------------------------ 10ms Feb 07 18:11:48 volumio volumio[13969]: debug: No callbacks for volumiosetvolume Feb 07 18:11:48 volumio volumio[13969]: info: VolumeController::SetAlsaVolume4 Feb 07 18:11:48 volumio volumio[13969]: debug: No callbacks for volumioupdatevolume Feb 07 18:11:48 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:48 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:48 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:48 volumio volumio[13969]: info: Feb 07 18:11:48 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:48 volumio volumio[13969]: info: Feb 07 18:11:48 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:48 volumio volumio[13969]: info: Feb 07 18:11:48 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 18:11:48 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:48 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:48 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:48 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:48 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:48 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:48 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:48 volumio volumio[13969]: info: ------------------------------ 8ms Feb 07 18:11:48 volumio volumio[13969]: info: ------------------------------ 7ms Feb 07 18:11:48 volumio volumio[13969]: info: ------------------------------ 6ms Feb 07 18:11:49 volumio volumio[13969]: debug: No callbacks for volumiosetvolume Feb 07 18:11:49 volumio volumio[13969]: info: VolumeController::SetAlsaVolume73 Feb 07 18:11:49 volumio volumio[13969]: debug: No callbacks for volumioupdatevolume Feb 07 18:11:49 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:49 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:49 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:49 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:49 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:49 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:49 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:49 volumio volumio[13969]: info: Feb 07 18:11:49 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:49 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:49 volumio volumio[13969]: info: Feb 07 18:11:49 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:49 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:49 volumio volumio[13969]: info: Feb 07 18:11:49 volumio volumio[13969]: ---------------------------- MPD announces state update: mixer Feb 07 18:11:49 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:49 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:49 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:49 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:49 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:49 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:49 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:49 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:49 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:49 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:49 volumio volumio[13969]: info: ------------------------------ 6ms Feb 07 18:11:49 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 07 18:11:49 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:49 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:49 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:49 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:49 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:49 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:49 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:49 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:49 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:49 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:49 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:49 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:49 volumio volumio[13969]: info: ------------------------------ 7ms Feb 07 18:11:49 volumio volumio[13969]: info: ------------------------------ 6ms Feb 07 18:11:50 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::volumioPlay Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::play index undefined Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::startPlaybackTimer Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: [1770484313895] ControllerVolusonic::resume Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::resume Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand play Feb 07 18:11:53 volumio volumio[13969]: info: [1770484313898] ControllerVolusonic: MPD player state update Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:53 volumio volumio[13969]: info: Feb 07 18:11:53 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand play took 4 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:53 volumio volumio[13969]: info: Feb 07 18:11:53 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:53 volumio volumio[13969]: info: Feb 07 18:11:53 volumio volumio[13969]: ---------------------------- MPD announces state update: player Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::getState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand status Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand status took 6 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand status took 4 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand status took 3 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand status took 2 milliseconds Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseState Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 07 18:11:53 volumio volumio[13969]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:53 volumio volumio[13969]: verbose: ControllerMpd::parseTrackInfo Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: [1770484313912] ControllerVolusonic::pushState Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: verbose: STATE SERVICE {"status":"play","position":0,"seek":6481,"duration":321,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1303 Kbps","isStreaming":false,"title":"Can I Have You for Myself?","artist":"By Storm","album":"My Ghosts Go Ghost","uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:53 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::syncState stateService play Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus pause Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:53 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:53 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:53 volumio volumio[13969]: info: [1770484313918] ControllerVolusonic::pushState Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: verbose: STATE SERVICE {"status":"play","position":0,"seek":6481,"duration":321,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1303 Kbps","isStreaming":false,"title":"Can I Have You for Myself?","artist":"By Storm","album":"My Ghosts Go Ghost","uri":"http://192.168.2.158:4533/rest/stream.view?id=uN8gvXmsghbPu55kQ6TxcN&format=raw&u=Miles&t=02bae9bed6c8c7fd6ab502997895dffa&s=IDxPx&v=1.10.2&f=json&c=volusonic","trackType":""} Feb 07 18:11:53 volumio volumio[13969]: verbose: CURRENT POSITION 0 Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::syncState stateService play Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::syncState currentStatus play Feb 07 18:11:53 volumio volumio[13969]: info: Received an update from plugin. extracting info from payload Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:53 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:53 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:53 volumio volumio[13969]: info: CoreStateMachine::pushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::getState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::volumioPushState Feb 07 18:11:53 volumio volumio[13969]: debug: API:pushState Feb 07 18:11:53 volumio volumio[13969]: debug: No callbacks for volumioPushState Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:53 volumio volumio[13969]: info: ControllerMpd::pushState Feb 07 18:11:53 volumio volumio[13969]: info: CoreCommandRouter::servicePushState Feb 07 18:11:53 volumio volumio[13969]: debug: CoreStateMachine::syncState Feb 07 18:11:53 volumio volumio[13969]: info: CorePlayQueue::getTrack 0 Feb 07 18:11:53 volumio volumio[13969]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd Feb 07 18:11:53 volumio volumio[13969]: info: ------------------------------ 32ms Feb 07 18:11:53 volumio volumio[13969]: info: ------------------------------ 28ms Feb 07 18:11:53 volumio volumio[13969]: info: ------------------------------ 27ms Feb 07 18:11:55 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:12:00 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:12:02 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 07 18:12:02 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 07 18:12:05 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:12:05 volumio volumio[13969]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Getting UI Config for language code: en Feb 07 18:12:05 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Successfully loaded UIConfig. Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing section: General Settings Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: CALIBRATE_BUTTON Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_SPEED_HIGH: 100 Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_SPEED_MEDIUM: 50 Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_SPEED_LOW: 10 Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for UPDATE_VOLUME_ON_MOVE: false Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for UPDATE_SEEK_ON_MOVE: false Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing section: Fader Behavior Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_0_CONFIGURED Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_0_BEHAVIOR Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_0_TRIM Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_1_CONFIGURED Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_1_BEHAVIOR Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_1_TRIM Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_2_CONFIGURED Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_2_BEHAVIOR Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_2_TRIM Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_3_CONFIGURED Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_3_BEHAVIOR Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] No value found in config for: FADER_3_TRIM Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Unpacking fader config for section: section_fader_behavior Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 0 configuration: {"FADER_IDX":0,"OUTPUT":"seek","INPUT":"seek","SEEK_TYPE":"track","CONTROL_TYPE":"track"} Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_0_CONFIGURED updated to : true Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_0_BEHAVIOR updated to : {"value":"track","label":"Track"} Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_0_TRIM updated to : [0,100] Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 1 configuration: {"FADER_IDX":1,"OUTPUT":"seek","INPUT":"seek","SEEK_TYPE":"track","CONTROL_TYPE":"track"} Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_1_CONFIGURED updated to : true Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_1_BEHAVIOR updated to : {"value":"track","label":"Track"} Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_1_TRIM updated to : [0,100] Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_2_CONFIGURED updated to : false Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_2_BEHAVIOR updated to : {"value":"volume","label":"Volume"} Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_2_TRIM updated to : [0,100] Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_3_CONFIGURED updated to : false Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_3_BEHAVIOR updated to : {"value":"volume","label":"Volume"} Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] FADER_3_TRIM updated to : [0,100] Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing section: Advanced Settings Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for SERIAL_PORT: "/dev/ttyUSB0" Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for BAUD_RATE: 1000000 Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_MESSAGE_DELAY: 0.1 Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_CALIBRATION_ON_START: true Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing section: Development Settings Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_REALTIME_SEEK_INTERVAL: 900 Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for DEBUG_MODE: true Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_MIDI_LOG: false Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_VALUE_LOG: false Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for FADER_CONTROLLER_MOVE_LOG: true Feb 07 18:12:05 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Set value for LOG_LEVEL: {"value":"debug","label":"Debug"} Feb 07 18:12:10 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:12:15 volumio volumio[13969]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 4 Transport: polling Total Clients: 21 Feb 07 18:12:16 volumio volumio[13969]: info: CALLMETHOD: system_hardware motorized_fader_control saveFaderElement [object Object] Feb 07 18:12:16 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: motorized_fader_control , saveFaderElement Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Saving fader elements: Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacking fader configuration. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 0... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 0 raw data: {"configured":true,"behavior":{"label":"Volume","value":"volume"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 0 is configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 0 configuration: CONTROL_TYPE=volume, CONFIGURED=true, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 1... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 1 raw data: {"configured":true,"behavior":{"value":"track","label":"Track"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 1 is configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 1 configuration: CONTROL_TYPE=track, CONFIGURED=true, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 2... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 2 raw data: {"configured":false,"behavior":{"value":"volume","label":"Volume"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 2 is not configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 2 configuration: CONTROL_TYPE=volume, CONFIGURED=false, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 3... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 3 raw data: {"configured":false,"behavior":{"value":"volume","label":"Volume"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 3 is not configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 3 configuration: CONTROL_TYPE=volume, CONFIGURED=false, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Final fader behavior array: [{"FADER_IDX":0,"CONTROL_TYPE":"volume"},{"FADER_IDX":1,"CONTROL_TYPE":"track"},{"FADER_IDX":2,"CONTROL_TYPE":"volume"},{"FADER_IDX":3,"CONTROL_TYPE":"volume"}] Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Final fader indexes array: [0,1] Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Final fader trim map: {"0":[0,100],"1":[0,100]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader configuration saved successfully. Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Restarting motorized fader control plugin... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Stopping motorized fader control plugin... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Stopping FaderController... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Move: {"indexes":[0,1],"targets":[0,0],"speeds":[50,50],"resolution":1} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Fader 0 speedFactor: 1.00, effectiveSpeed: 50.00 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Fader 1 speedFactor: 1.00, effectiveSpeed: 50.00 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Generated {"0":1,"1":1} positions Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] First position: 0, Last position: 0 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Event triggered: FaderController/error Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [FaderController] FaderController stopped successfully Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Fader Controller stopped successfully Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Stopping FaderController... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Unsubscribed from event: playback/playing Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Unsubscribed from event: playback/paused Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Unsubscribed from event: playback/stopped Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Unsubscribed from event: playback/playing Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Unsubscribed from event: playback/paused Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Unsubscribed from event: playback/stopped Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Stopping services... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Plugin stopped successfully! Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Restarting FaderController... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Log level changed to: debug Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Log messages initialized successfully. Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Starting motorized fader control plugin... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Initializing core components... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Setting up plugin... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Initializing FaderController... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] emitting configChange for fader 0 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] emitting configChange for fader 1 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] [motorized_fader_control] [FaderController] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] MIDILog: false Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] ValueLog: false Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] MoveLog: true Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] messageDelay: 0.1 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] speeds: 100,50,10 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] faderIndexes: 0,1 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] queueOverflow: 10000000 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] calibrateOnStart: true Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Fader 0: {"index":0,"position":0,"progression":0,"rawPosition":0,"rawProgression":0,"touch":false,"echoMode":false,"progressionMap":[0,100],"speedFactor":1} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Fader 1: {"index":1,"position":0,"progression":0,"rawPosition":0,"rawProgression":0,"touch":false,"echoMode":false,"progressionMap":[0,100],"speedFactor":1} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] [motorized_fader_control] [FaderController] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Event registered: fader/update Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Starting FaderController... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Event triggered: FaderController/error Feb 07 18:12:16 volumio volumio[13969]: info: CALLMETHOD: system_hardware motorized_fader_control saveFaderElement [object Object] Feb 07 18:12:16 volumio volumio[13969]: info: CoreCommandRouter::executeOnPlugin: motorized_fader_control , saveFaderElement Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Saving fader elements: Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacking fader configuration. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 0... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 0 raw data: {"configured":true,"behavior":{"label":"Volume","value":"volume"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 0 is configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 0 configuration: CONTROL_TYPE=volume, CONFIGURED=true, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 1... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 1 raw data: {"configured":true,"behavior":{"value":"track","label":"Track"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 1 is configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 1 configuration: CONTROL_TYPE=track, CONFIGURED=true, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 2... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 2 raw data: {"configured":false,"behavior":{"value":"volume","label":"Volume"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 2 is not configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 2 configuration: CONTROL_TYPE=volume, CONFIGURED=false, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Processing fader 3... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 3 raw data: {"configured":false,"behavior":{"value":"volume","label":"Volume"},"trim":[[0,100]]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader 3 is not configured. Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Repacked Fader 3 configuration: CONTROL_TYPE=volume, CONFIGURED=false, TRIM=0,100 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Final fader behavior array: [{"FADER_IDX":0,"CONTROL_TYPE":"volume"},{"FADER_IDX":1,"CONTROL_TYPE":"track"},{"FADER_IDX":2,"CONTROL_TYPE":"volume"},{"FADER_IDX":3,"CONTROL_TYPE":"volume"}] Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Final fader indexes array: [0,1] Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Final fader trim map: {"0":[0,100],"1":[0,100]} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [MAIN] Fader configuration saved successfully. Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Restarting motorized fader control plugin... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Stopping motorized fader control plugin... Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] -------------------------------------------------------------------- Feb 07 18:12:16 volumio volumio[13969]: info: [motorized_fader_control] [MAIN] Stopping FaderController... Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Move: {"indexes":[0,1],"targets":[0,0],"speeds":[50,50],"resolution":1} Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Fader 0 speedFactor: 1.00, effectiveSpeed: 50.00 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Fader 1 speedFactor: 1.00, effectiveSpeed: 50.00 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] Generated {"0":1,"1":1} positions Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [FaderController] First position: 0, Last position: 0 Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Event triggered: FaderController/error Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Event triggered: FaderController/error Feb 07 18:12:16 volumio volumio[13969]: debug: [motorized_fader_control] [EVENTBUS] Event triggered: FaderController/error Feb 07 18:12:16 volumio volumio[13969]: error: [motorized_fader_control] [FaderController] Shutdown error: Feb 07 18:12:16 volumio volumio[13969]: error: [motorized_fader_control] [MAIN] Error stopping FaderController: Serial port not open Feb 07 18:12:16 volumio volumio[13969]: error: [motorized_fader_control] [MAIN] Error stopping Fader Controller: Serial port not open Feb 07 18:12:16 volumio volumio[13969]: warn: [motorized_fader_control] [MAIN] An error occurred trying to stop the FaderController. Forced closing serial connection. Feb 07 18:12:16 volumio volumio[13969]: error: [motorized_fader_control] [MAIN] Error stopping plugin: Serial port not open Feb 07 18:12:16 volumio volumio[13969]: error: [motorized_fader_control] [MAIN] Error restarting plugin: Serial port not open Feb 07 18:12:16 volumio volumio[13969]: error: [motorized_fader_control] [MAIN] Error saving fader elements: Serial port not open Feb 07 18:12:16 volumio volumio[13969]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 18:12:16 volumio volumio[13969]: Error: Serial port not open Feb 07 18:12:16 volumio volumio[13969]: at /data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:306:21 Feb 07 18:12:16 volumio volumio[13969]: at new Promise () Feb 07 18:12:16 volumio volumio[13969]: at MIDIQueue.send (/data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:298:12) Feb 07 18:12:16 volumio volumio[13969]: at /data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:256:24 Feb 07 18:12:16 volumio volumio[13969]: at Array.map () Feb 07 18:12:16 volumio volumio[13969]: at MIDIQueue.process (/data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:243:41) Feb 07 18:12:16 volumio volumio[13969]: at /data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:218:12 Feb 07 18:12:16 volumio volumio[13969]: at new Promise () Feb 07 18:12:16 volumio volumio[13969]: at MIDIQueue.add (/data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:189:12) Feb 07 18:12:16 volumio volumio[13969]: at /data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:709:31 Feb 07 18:12:16 volumio volumio[13969]: at Array.map () Feb 07 18:12:16 volumio volumio[13969]: at FaderController.sendPositions (/data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:703:35) Feb 07 18:12:16 volumio volumio[13969]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 07 18:12:16 volumio volumio[13969]: at async FaderController.moveFaders (/data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:571:5) Feb 07 18:12:16 volumio volumio[13969]: at async FaderController.stop (/data/plugins/system_hardware/motorized_fader_control/lib/FaderController.js:1016:7) Feb 07 18:12:16 volumio volumio[13969]: at async motorizedFaderControl._stopFaderController (/data/plugins/system_hardware/motorized_fader_control/index.js:206:3) { Feb 07 18:12:16 volumio volumio[13969]: code: 'MOVEMENT_ERROR', Feb 07 18:12:16 volumio volumio[13969]: positions: [ { index: 0, value: 0 }, { index: 1, value: 0 } ] Feb 07 18:12:16 volumio volumio[13969]: } Feb 07 18:12:16 volumio volumio[13969]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 18:12:17 volumio sudo[15252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 18:11' Feb 07 18:12:17 volumio sudo[15252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"