-- Logs begin at Sat 2025-01-18 15:13:38 +07, end at Sat 2025-01-18 15:18:49 +07. -- Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29887, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29894, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29901, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29908, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29915, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29924, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29931, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29938, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29945, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29952, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29959, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29966, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29973, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29980, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29987, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 29994, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30001, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30008, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30015, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30022, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30029, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30036, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30043, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30050, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30057, instance 1, run: true Jan 18 15:17:00 volumio volumio[929]: info: camilladsp spawned new process with pid 30064, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30071, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30078, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30085, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30092, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30099, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30106, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30115, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30122, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30129, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30136, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30143, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30150, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30157, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30164, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30171, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30178, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30185, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30192, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30199, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30206, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30213, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30220, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30227, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30234, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30241, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30248, instance 1, run: true Jan 18 15:17:01 volumio volumio[929]: info: camilladsp spawned new process with pid 30255, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30262, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30269, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30276, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30283, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30290, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30297, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30304, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30313, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30320, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30327, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30334, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30341, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30348, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30355, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30362, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30369, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30376, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30383, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30390, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30400, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30407, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30414, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30421, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30428, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30435, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30442, instance 1, run: true Jan 18 15:17:02 volumio volumio[929]: info: camilladsp spawned new process with pid 30449, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30456, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30463, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30470, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30477, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30484, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30491, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30498, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30507, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30514, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30521, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30528, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30535, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30542, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30549, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30556, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30563, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30570, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30577, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30584, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30591, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30598, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30605, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30612, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30619, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30626, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30633, instance 1, run: true Jan 18 15:17:03 volumio volumio[929]: info: camilladsp spawned new process with pid 30640, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30647, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30654, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30661, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30668, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30675, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30682, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30689, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30696, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30705, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30712, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30719, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30726, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30733, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30740, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30747, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30754, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30761, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30768, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30775, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30782, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30789, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30796, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30803, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30810, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30817, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30824, instance 1, run: true Jan 18 15:17:04 volumio volumio[929]: info: camilladsp spawned new process with pid 30831, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30838, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30845, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30852, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30859, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30866, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30873, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30880, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30887, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30896, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30903, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30910, instance 1, run: true Jan 18 15:17:05 volumio ntpd[1388]: Soliciting pool server 115.165.161.155 Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30917, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30924, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30931, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30938, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30945, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30952, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30959, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30966, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30973, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30980, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30987, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 30994, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 31001, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 31008, instance 1, run: true Jan 18 15:17:05 volumio volumio[929]: info: camilladsp spawned new process with pid 31015, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31022, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31029, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31036, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31043, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31050, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31057, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31064, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31071, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31078, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31087, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31094, instance 1, run: true Jan 18 15:17:06 volumio ntpd[1388]: Soliciting pool server 115.165.161.155 Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31101, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31108, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31115, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31122, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31129, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31136, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31143, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31150, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31157, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31164, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31171, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31192, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31199, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31206, instance 1, run: true Jan 18 15:17:06 volumio volumio[929]: info: camilladsp spawned new process with pid 31213, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31220, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31227, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31234, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31241, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31248, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31255, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31262, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31269, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31276, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31283, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31292, instance 1, run: true Jan 18 15:17:07 volumio ntpd[1388]: Soliciting pool server 2400:6760:0:200::254 Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31299, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31306, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31313, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31320, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31327, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31334, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31341, instance 1, run: true Jan 18 15:17:07 volumio volumio[929]: info: camilladsp spawned new process with pid 31348, instance 1, run: true Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31356, instance 1, run: true Jan 18 15:17:08 volumio kernel: usb 2-1: new full-speed USB device number 3 using uhci_hcd Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31363, instance 1, run: true Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31370, instance 1, run: true Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31377, instance 1, run: true Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31384, instance 1, run: true Jan 18 15:17:08 volumio kernel: usb 2-1: New USB device found, idVendor=8888, idProduct=1719, bcdDevice= 1.00 Jan 18 15:17:08 volumio kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Jan 18 15:17:08 volumio kernel: usb 2-1: Product: DA310 USB Audio Jan 18 15:17:08 volumio kernel: usb 2-1: Manufacturer: MV-SILICON Jan 18 15:17:08 volumio kernel: usb 2-1: SerialNumber: 20190808 Jan 18 15:17:08 volumio kernel: input: MV-SILICON DA310 USB Audio as /devices/pci0000:00/0000:00:1d.1/usb2/2-1/2-1:1.3/0003:8888:1719.0003/input/input15 Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31392, instance 1, run: true Jan 18 15:17:08 volumio kernel: hid-generic 0003:8888:1719.0003: input,hidraw2: USB HID v2.01 Device [MV-SILICON DA310 USB Audio] on usb-0000:00:1d.1-1/input3 Jan 18 15:17:08 volumio kernel: usbhid 2-1:1.4: couldn't find an input interrupt endpoint Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31408, instance 1, run: true Jan 18 15:17:08 volumio systemd-udevd[31401]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31418, instance 1, run: true Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31425, instance 1, run: true Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31432, instance 1, run: true Jan 18 15:17:08 volumio kernel: usb 2-1: Warning! Unlikely big volume range (=4096), cval->res is probably wrong. Jan 18 15:17:08 volumio kernel: usb 2-1: [2] FU [PCM Playback Volume] ch = 2, val = 0/4096/1 Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31439, instance 1, run: true Jan 18 15:17:08 volumio kernel: usb 2-1: Warning! Unlikely big volume range (=4096), cval->res is probably wrong. Jan 18 15:17:08 volumio kernel: usb 2-1: [5] FU [Mic Capture Volume] ch = 2, val = 0/4096/1 Jan 18 15:17:08 volumio kernel: usbcore: registered new interface driver snd-usb-audio Jan 18 15:17:08 volumio volumio[929]: info: camilladsp spawned new process with pid 31446, instance 1, run: true Jan 18 15:17:09 volumio volumio[929]: info: No valid Plugin REST Endpoint Jan 18 15:17:09 volumio volumio[929]: info: Jan 18 15:17:09 volumio volumio[929]: ---------------------------- USB Audio Device Attached Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::Close All Modals sent Jan 18 15:17:09 volumio volumio[929]: info: Preparing to save Alsa Options, stopping services first Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::volumioGetState Jan 18 15:17:09 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::volumioPause Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::pause Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::stPlaybackTimer Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::servicePause Jan 18 15:17:09 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::servicePause Jan 18 15:17:09 volumio volumio[929]: info: ControllerMpd::pause Jan 18 15:17:09 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand pause Jan 18 15:17:09 volumio volumio[929]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"DA310 USB Audio","alsacard":"Audio"},"i2s":false} Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 18 15:17:09 volumio volumio[929]: info: Setting mixer PCM for card DA310 USB Audio Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 18 15:17:09 volumio volumio[929]: info: Updating Volume Controller Parameters: Device: 5 Name: DA310 USB Audio Mixer: PCM Max Vol: 90 Vol Curve; logarithmic Vol Steps: 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 18 15:17:09 volumio volumio[929]: info: Disabling external Volume Control Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 18 15:17:09 volumio volumio[929]: info: Preparing to generate the ALSA configuration file Jan 18 15:17:09 volumio volumio[929]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 18 15:17:09 volumio volumio[929]: info: Reading ALSA contributions from plugins. Jan 18 15:17:09 volumio volumio[929]: info: Jan 18 15:17:09 volumio volumio[929]: ---------------------------- MPD announces state update: player Jan 18 15:17:09 volumio volumio[929]: info: sendMpdCommand pause took 390 milliseconds Jan 18 15:17:09 volumio volumio[929]: info: ControllerMpd::getState Jan 18 15:17:09 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand status Jan 18 15:17:09 volumio volumio[929]: verbose: [ytcr] MPDSubsystemEventEmitter invoking 1 SubsystemEventListener callbacks for: player Jan 18 15:17:09 volumio volumio[929]: info: sendMpdCommand status took 62 milliseconds Jan 18 15:17:09 volumio volumio[929]: verbose: ControllerMpd::parseState Jan 18 15:17:09 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 15:17:09 volumio volumio[929]: info: sendMpdCommand playlistinfo took 16 milliseconds Jan 18 15:17:09 volumio volumio[929]: verbose: ControllerMpd::parseTrackInfo Jan 18 15:17:09 volumio volumio[929]: info: ControllerMpd::pushState Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::servicePushState Jan 18 15:17:09 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:09 volumio volumio[929]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":463,"duration":352,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"ben em dang co ta","artist":null,"album":"Album chon loc 13","uri":"USB/New_Volume/nhac dsd/Album chon loc 13/ben em dang co ta.dsf","trackType":"dsf"} Jan 18 15:17:09 volumio volumio[929]: verbose: CURRENT POSITION 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::syncState stateService pause Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::syncState currentStatus pause Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:17:09 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::stPlaybackTimer Jan 18 15:17:09 volumio volumio[929]: info: ------------------------------ 101ms Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 18 15:17:09 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:17:09 volumio volumio[929]: info: VolumeController:: Volume=90 Mute =false Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::volumioGetState Jan 18 15:17:09 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:17:09 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:17:09 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:17:09 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:17:09 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:17:09 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:17:09 volumio volumio[929]: info: Asound.conf file unchanged, so no further update is needed Jan 18 15:17:09 volumio volumio[929]: info: Output device has changed, restarting MPD Jan 18 15:17:09 volumio sudo[31478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 18 15:17:09 volumio sudo[31478]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 18 15:17:09 volumio sudo[31478]: pam_unix(sudo:session): session closed for user root Jan 18 15:17:09 volumio volumio[929]: info: Output device has changed, restarting Shairport Sync Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 18 15:17:09 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 18 15:17:10 volumio sudo[31481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 18 15:17:10 volumio sudo[31481]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 18 15:17:10 volumio systemd[1]: musicservicesshield.service: Succeeded. Jan 18 15:17:10 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Jan 18 15:17:10 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Jan 18 15:17:10 volumio systemd[1]: Stopping Music Player Daemon... Jan 18 15:17:10 volumio systemd[1]: mpd.service: Succeeded. Jan 18 15:17:10 volumio systemd[1]: Stopped Music Player Daemon. Jan 18 15:17:10 volumio systemd[1]: Starting Music Player Daemon... Jan 18 15:17:10 volumio volumio[929]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 18 15:17:10 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Jan 18 15:17:10 volumio volumio[929]: info: MPD Permissions set Jan 18 15:17:10 volumio volumio[929]: verbose: [ytcr] MPDSubsystemEventEmitter destroyed. Jan 18 15:17:10 volumio volumio[929]: verbose: [ytcr] Cancelling prefetch (abortIfPrefetching: true, clearIfPrefetched: true) Jan 18 15:17:10 volumio volumio[929]: info: CoreCommandRouter::volumioGetState Jan 18 15:17:10 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:10 volumio volumio[929]: verbose: [ytcr] MPD disconnected. Reconnecting... Jan 18 15:17:10 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 18 15:17:10 volumio sudo[31486]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 18 15:17:10 volumio sudo[31486]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 18 15:17:10 volumio sudo[31486]: pam_unix(sudo:session): session closed for user root Jan 18 15:17:10 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 18 15:17:10 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 18 15:17:10 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 18 15:17:10 volumio volumio[929]: info: Starting Shairport Sync Jan 18 15:17:10 volumio sudo[31496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 18 15:17:10 volumio sudo[31496]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 18 15:17:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 18 15:17:10 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 18 15:17:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 18 15:17:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 18 15:17:10 volumio sudo[31496]: pam_unix(sudo:session): session closed for user root Jan 18 15:17:10 volumio volumio[929]: info: Shairport-Sync Started Jan 18 15:17:10 volumio mpd[31489]: Jan 18 15:17 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 18 15:17:11 volumio systemd[1]: Started Music Player Daemon. Jan 18 15:17:11 volumio sudo[31481]: pam_unix(sudo:session): session closed for user root Jan 18 15:17:11 volumio volumio[929]: error: updateQueue error: null Jan 18 15:17:11 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Jan 18 15:17:11 volumio volumio[929]: verbose: [ytcr] MPD connected Jan 18 15:17:11 volumio volumio[929]: verbose: [ytcr] MPDSubsystemEventEmitter enabled. Jan 18 15:17:11 volumio volumio[31503]: cset: --> shielding system active with Jan 18 15:17:11 volumio volumio[31503]: cset: "system" cpuset of CPUSPEC(1) with 192 tasks running Jan 18 15:17:11 volumio volumio[31503]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Jan 18 15:17:11 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jan 18 15:17:13 volumio volumio[929]: info: CoreStateMachine::getcurrentVolume Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioRetrievevolume Jan 18 15:17:13 volumio volumio[929]: info: VolumeController:: Volume=90 Mute =false Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioGetState Jan 18 15:17:13 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:13 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:17:13 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:17:13 volumio volumio[929]: info: CoreStateMachine::updateTrackBlock Jan 18 15:17:13 volumio volumio[929]: info: CorePlayQueue::getTrackBlock Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioRetrievevolume Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:17:13 volumio volumio[929]: info: VolumeController:: Volume=90 Mute =false Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioGetState Jan 18 15:17:13 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:13 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:17:13 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:13 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:17:13 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:17:13 volumio volumio[929]: error: Upnp client error: Error: This socket has been ended by the other party Jan 18 15:17:13 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:17:13 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 11) (YouTube) Incoming message: 'noop' Jan 18 15:17:13 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 11) (YouTube) Not handled: 'noop' Jan 18 15:17:15 volumio volumio[929]: info: camilladsp spawned new process with pid 31535, instance 1, run: true Jan 18 15:17:15 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:17:15 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 11) (YouTube Music) Incoming message: 'noop' Jan 18 15:17:15 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 11) (YouTube Music) Not handled: 'noop' Jan 18 15:17:18 volumio ntpd[1388]: Soliciting pool server 103.184.124.254 Jan 18 15:17:25 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:17:26 volumio volumio[929]: info: Preload queue cleared Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NjguZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NjkuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzAuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzEuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzIuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzMuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzQuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzUuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzYuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzcuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzguZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzkuZmxhYz9hbGJ1bWlkPTc5 Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NjguZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NjkuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzAuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzEuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzIuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzMuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzQuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzUuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzYuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzcuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzguZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:26 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy83OS8tMi81NzkuZmxhYz9hbGJ1bWlkPTc5 in service upnp_browser Jan 18 15:17:36 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:17:36 volumio volumio[929]: info: Preload queue cleared Jan 18 15:17:36 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8zMTkvLTIvMjE2NC53YXY/YWxidW1pZD0zMTk= Jan 18 15:17:36 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8zMTkvLTIvMjE2NC53YXY/YWxidW1pZD0zMTk= in service upnp_browser Jan 18 15:17:41 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:17:41 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 12) (YouTube) Incoming message: 'noop' Jan 18 15:17:41 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 12) (YouTube) Not handled: 'noop' Jan 18 15:17:42 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:17:42 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 12) (YouTube Music) Incoming message: 'noop' Jan 18 15:17:42 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 12) (YouTube Music) Not handled: 'noop' Jan 18 15:17:57 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:17:57 volumio volumio[929]: info: Preload queue cleared Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzAuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzEuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzIuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzMuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzQuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzUuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzYuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzcuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Preloading song: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzguZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzAuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzEuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzIuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzMuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzQuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzUuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzYuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzcuZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:57 volumio volumio[929]: info: Exploding uri upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzguZmxhYz9hbGJ1bWlkPTIw in service upnp_browser Jan 18 15:17:59 volumio volumio[929]: info: Preload queue cleared Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::ClearQueue Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::stop Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::updateTrackBlock Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrackBlock Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::stPlaybackTimer Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::serviceStop Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrack 1 Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::serviceStop Jan 18 15:17:59 volumio volumio[929]: info: ControllerMpd::stop Jan 18 15:17:59 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand stop Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::clearPlayQueue Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::saveQueue Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::volumioPushQueue Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::addQueueItems Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::addQueueItems Jan 18 15:17:59 volumio volumio[929]: info: Preload queue cleared Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzAuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzAuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::volumioPushQueue Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::saveQueue Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::updateTrackBlock Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrackBlock Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::volumioPlay Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::play index 0 Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::addQueueItems Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::addQueueItems Jan 18 15:17:59 volumio volumio[929]: info: Preload queue cleared Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzEuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzEuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzIuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzIuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzMuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzMuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzQuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzQuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzUuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzUuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzYuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzYuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzcuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzcuZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Adding Item to queue: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzguZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: Using cached record of: upnp/http://192.168.2.10:1932/ContentDirectory/432af489-bd12-663c-119d-c91f22bdf604/control.xml@bXVzaWNkYjovL2FsYnVtcy8yMC8tMi8xNzguZmxhYz9hbGJ1bWlkPTIw Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::stop Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 18 15:17:59 volumio volumio[929]: info: CoreCommandRouter::volumioPushQueue Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::saveQueue Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::play index undefined Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::updateTrackBlock Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrackBlock Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrack 0 Jan 18 15:17:59 volumio volumio[929]: info: CoreStateMachine::startPlaybackTimer Jan 18 15:17:59 volumio volumio[929]: info: CorePlayQueue::getTrack 0 Jan 18 15:17:59 volumio volumio[929]: info: [1737188279967] ControllerUPNPBrowser::clearAddPlayTrack Jan 18 15:17:59 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand stop Jan 18 15:17:59 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:17:59 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:17:59 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:17:59 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:17:59 volumio volumio[929]: info: sendMpdCommand stop took 42 milliseconds Jan 18 15:17:59 volumio volumio[929]: info: sendMpdCommand stop took 18 milliseconds Jan 18 15:17:59 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand clear Jan 18 15:17:59 volumio volumio[929]: info: Jan 18 15:17:59 volumio volumio[929]: ---------------------------- MPD announces system playlist update Jan 18 15:17:59 volumio volumio[929]: info: Ignoring MPD Status Update Jan 18 15:17:59 volumio volumio[929]: info: sendMpdCommand clear took 1 milliseconds Jan 18 15:17:59 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.10:1932/%25/b02ae65dfc644ab8472c502086d344cd/01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac" Jan 18 15:18:00 volumio volumio[929]: error: updateQueue error: null Jan 18 15:18:00 volumio volumio[929]: info: ------------------------------ 31ms Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.10:1932/%25/b02ae65dfc644ab8472c502086d344cd/01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac" Jan 18 15:18:00 volumio volumio[929]: info: Jan 18 15:18:00 volumio volumio[929]: ---------------------------- MPD announces system playlist update Jan 18 15:18:00 volumio volumio[929]: info: Ignoring MPD Status Update Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand add "http://192.168.2.10:1932/%25/b02ae65dfc644ab8472c502086d344cd/01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac" took 1 milliseconds Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand play Jan 18 15:18:00 volumio volumio[929]: info: ------------------------------ 2ms Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand play took 1 milliseconds Jan 18 15:18:00 volumio volumio[929]: info: Jan 18 15:18:00 volumio volumio[929]: ---------------------------- MPD announces state update: player Jan 18 15:18:00 volumio volumio[929]: info: ControllerMpd::getState Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand status Jan 18 15:18:00 volumio volumio[929]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 18 15:18:00 volumio volumio[929]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 18 15:18:00 volumio volumio[929]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 18 15:18:00 volumio volumio[929]: info: Jan 18 15:18:00 volumio volumio[929]: ---------------------------- MPD announces state update: player Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand status took 15 milliseconds Jan 18 15:18:00 volumio volumio[929]: info: ControllerMpd::getState Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand status Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::parseState Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand status took 1 milliseconds Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::parseState Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::parseTrackInfo Jan 18 15:18:00 volumio volumio[929]: info: ControllerMpd::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::servicePushState Jan 18 15:18:00 volumio volumio[929]: info: CorePlayQueue::getTrack 0 Jan 18 15:18:00 volumio volumio[929]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":307,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac","artist":null,"album":null,"uri":"http://192.168.2.10:1932/%25/b02ae65dfc644ab8472c502086d344cd/01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac","trackType":"flac"} Jan 18 15:18:00 volumio volumio[929]: verbose: CURRENT POSITION 0 Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::syncState stateService play Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::syncState currentStatus stop Jan 18 15:18:00 volumio volumio[929]: info: ------------------------------ 17ms Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::parseTrackInfo Jan 18 15:18:00 volumio volumio[929]: info: ControllerMpd::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::servicePushState Jan 18 15:18:00 volumio volumio[929]: info: CorePlayQueue::getTrack 0 Jan 18 15:18:00 volumio volumio[929]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":307,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac","artist":null,"album":null,"uri":"http://192.168.2.10:1932/%25/b02ae65dfc644ab8472c502086d344cd/01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac","trackType":"flac"} Jan 18 15:18:00 volumio volumio[929]: verbose: CURRENT POSITION 0 Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::syncState stateService play Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::syncState currentStatus play Jan 18 15:18:00 volumio volumio[929]: info: Received an update from plugin. extracting info from payload Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:18:00 volumio volumio[929]: info: ------------------------------ 16ms Jan 18 15:18:00 volumio volumio[929]: verbose: [ytcr] MPDSubsystemEventEmitter invoking 1 SubsystemEventListener callbacks for: player Jan 18 15:18:00 volumio volumio[929]: info: Jan 18 15:18:00 volumio volumio[929]: ---------------------------- MPD announces system playlist update Jan 18 15:18:00 volumio volumio[929]: info: Ignoring MPD Status Update Jan 18 15:18:00 volumio volumio[929]: info: Jan 18 15:18:00 volumio volumio[929]: ---------------------------- MPD announces state update: player Jan 18 15:18:00 volumio volumio[929]: info: ControllerMpd::getState Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand status Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:18:00 volumio volumio[929]: info: ------------------------------ 30ms Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand status took 20 milliseconds Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::parseState Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 15:18:00 volumio volumio[929]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 18 15:18:00 volumio volumio[929]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 18 15:18:00 volumio volumio[929]: verbose: ControllerMpd::parseTrackInfo Jan 18 15:18:00 volumio volumio[929]: info: ControllerMpd::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::servicePushState Jan 18 15:18:00 volumio volumio[929]: info: CorePlayQueue::getTrack 0 Jan 18 15:18:00 volumio volumio[929]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1206,"duration":307,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"711 Kbps","isStreaming":false,"title":"Một Mình","artist":"Lê Ngọc Phương Anh","album":"Một Cõi Tình Phai","uri":"http://192.168.2.10:1932/%25/b02ae65dfc644ab8472c502086d344cd/01.%2520M%25e1%25bb%2599t%2520M%25c3%25acnh%2520-%2520L%25c3%25aa%2520Ng%25e1%25bb%258dc%2520Ph%25c6%25b0%25c6%25a1ng%2520Anh.flac","trackType":"flac"} Jan 18 15:18:00 volumio volumio[929]: verbose: CURRENT POSITION 0 Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::syncState stateService play Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::syncState currentStatus play Jan 18 15:18:00 volumio volumio[929]: info: Received an update from plugin. extracting info from payload Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::pushState Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::volumioPushState Jan 18 15:18:00 volumio volumio[929]: info: ------------------------------ 56ms Jan 18 15:18:00 volumio volumio[929]: verbose: [ytcr] MPDSubsystemEventEmitter invoking 1 SubsystemEventListener callbacks for: player Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::volumioGetQueue Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::getQueue Jan 18 15:18:00 volumio volumio[929]: info: CorePlayQueue::getQueue Jan 18 15:18:00 volumio volumio[929]: info: CoreCommandRouter::volumioGetQueue Jan 18 15:18:00 volumio volumio[929]: info: CoreStateMachine::getQueue Jan 18 15:18:00 volumio volumio[929]: info: CorePlayQueue::getQueue Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: SPOTIFY VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: VOLUMIO VOLUME 90 Jan 18 15:18:00 volumio volumio[929]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 18 15:18:08 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:18:08 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 13) (YouTube Music) Incoming message: 'noop' Jan 18 15:18:08 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 13) (YouTube Music) Not handled: 'noop' Jan 18 15:18:09 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:18:09 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 13) (YouTube) Incoming message: 'noop' Jan 18 15:18:09 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 13) (YouTube) Not handled: 'noop' Jan 18 15:18:11 volumio ntpd[1388]: Soliciting pool server 103.184.124.254 Jan 18 15:18:11 volumio ntpd[1388]: Soliciting pool server 103.184.124.254 Jan 18 15:18:12 volumio ntpd[1388]: Soliciting pool server 2401:5f80:5001:1f::31f Jan 18 15:18:22 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 18 15:18:22 volumio volumio[929]: info: CURURI: music-library Jan 18 15:18:22 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:24 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 18 15:18:24 volumio volumio[929]: info: CURURI: music-library/USB Jan 18 15:18:24 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:25 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 18 15:18:25 volumio volumio[929]: info: CURURI: music-library/USB/New_Volume Jan 18 15:18:25 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:30 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:30 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:32 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:32 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:33 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:34 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:35 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:36 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:36 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 14) (YouTube Music) Incoming message: 'noop' Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 14) (YouTube Music) Not handled: 'noop' Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] RPC connection disconnected. Reconnecting... Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=13&CI=0&RID=rpc&SID=F32DF13D57303D54&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=-b3SQNUbLUD_WMZXmIgdRzfal9QXdndP&id=eec13241-706d-4267-8977-04dc894c3f13&loungeIdToken=AGdO5p-YGOyKfCnLYCaLedU94gLVb7wi7H6h1f1xX9RH5SupNilHmpeM6oI-flcgvw5u1reK76R_f6g1LTUFxGViOei7yFOwW2h6dg5HA2fUZDTCGiDlw0U&mdxVersion=2&name=YouTube%20on%20Volumio&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=79557f65a388 Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] RPC connection established. Jan 18 15:18:36 volumio volumio[929]: verbose: ----------------------------------- Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 15) (YouTube) Incoming message: 'noop' Jan 18 15:18:36 volumio volumio[929]: verbose: [yt-cast-receiver] (AID: 15) (YouTube) Not handled: 'noop' Jan 18 15:18:37 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:38 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:46 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:46 volumio volumio[929]: info: Preload queue cleared Jan 18 15:18:49 volumio volumio[929]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 15:18:49 volumio volumio[929]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 18 15:18:49 volumio volumio[929]: TypeError: Cannot read property 'length' of undefined Jan 18 15:18:49 volumio volumio[929]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jan 18 15:18:49 volumio volumio[929]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jan 18 15:18:49 volumio volumio[929]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jan 18 15:18:49 volumio volumio[929]: at Parser.emit (events.js:400:28) Jan 18 15:18:49 volumio volumio[929]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jan 18 15:18:49 volumio volumio[929]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jan 18 15:18:49 volumio volumio[929]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jan 18 15:18:49 volumio volumio[929]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jan 18 15:18:49 volumio volumio[929]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jan 18 15:18:49 volumio volumio[929]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jan 18 15:18:49 volumio volumio[929]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jan 18 15:18:49 volumio volumio[929]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jan 18 15:18:49 volumio volumio[929]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jan 18 15:18:49 volumio volumio[929]: at IncomingMessage.emit (events.js:412:35) Jan 18 15:18:49 volumio volumio[929]: at endReadableNT (internal/streams/readable.js:1333:12) Jan 18 15:18:49 volumio volumio[929]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jan 18 15:18:49 volumio volumio[929]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 18 15:18:49 volumio sudo[31819]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-18 15:17 Jan 18 15:18:49 volumio sudo[31819]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"