-- Logs begin at Thu 2019-02-14 15:41:59 IST, end at Mon 2024-11-25 21:35:51 IST. -- Nov 25 21:34:10 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 21:34:10 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 21:34:10 pi-poly volumio[853]: info: Discovery: Getting this device information Nov 25 21:34:10 pi-poly volumio[853]: info: CoreCommandRouter::volumioGetState Nov 25 21:34:10 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 21:34:15 pi-poly volumiologrotate[472]: ls: cannot access '/var/log/samba/log.wb-PI': No such file or directory Nov 25 21:34:15 pi-poly volumiologrotate[472]: ls: cannot access 'POLY+': No such file or directory Nov 25 21:34:40 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 21:34:40 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 21:34:40 pi-poly volumio[853]: info: Discovery: Getting this device information Nov 25 21:34:40 pi-poly volumio[853]: info: CoreCommandRouter::volumioGetState Nov 25 21:34:40 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 21:34:56 pi-poly volumio[853]: info: Creating user directories (if not exist) Nov 25 21:34:56 pi-poly sudo[4997]: pam_unix(sudo:session): session closed for user root Nov 25 21:34:56 pi-poly volumio[853]: info: Now Playing plugin installed Nov 25 21:34:56 pi-poly volumio[853]: Plugin install end detected on script Nov 25 21:34:56 pi-poly volumio[853]: info: Install script completed Nov 25 21:34:56 pi-poly volumio[853]: info: Adding reference to registry Nov 25 21:34:56 pi-poly volumio[853]: info: Done installing plugin. Nov 25 21:34:56 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 25 21:34:56 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 25 21:34:56 pi-poly volumio[853]: info: Folder /tmp/plugins removed Nov 25 21:34:56 pi-poly volumio[853]: info: Folder /tmp/downloaded_plugin.zip removed Nov 25 21:34:56 pi-poly volumio[853]: info: Folder /data/temp removed Nov 25 21:35:02 pi-poly volumio[853]: info: Enabling plugin now_playing Nov 25 21:35:02 pi-poly volumio[853]: info: Loading plugin "now_playing"... Nov 25 21:35:02 pi-poly volumio[853]: error: !!!! WARNING !!!! Nov 25 21:35:02 pi-poly volumio[853]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Nov 25 21:35:02 pi-poly volumio[853]: Require stack: Nov 25 21:35:02 pi-poly volumio[853]: - /data/plugins/user_interface/now_playing/dist/index.js Nov 25 21:35:02 pi-poly volumio[853]: - /volumio/app/pluginmanager.js Nov 25 21:35:02 pi-poly volumio[853]: - /volumio/app/index.js Nov 25 21:35:02 pi-poly volumio[853]: - /volumio/index.js Nov 25 21:35:02 pi-poly volumio[853]: error: Stack trace: Error: Cannot find module 'geo-tz' Nov 25 21:35:02 pi-poly volumio[853]: Require stack: Nov 25 21:35:02 pi-poly volumio[853]: - /data/plugins/user_interface/now_playing/dist/index.js Nov 25 21:35:02 pi-poly volumio[853]: - /volumio/app/pluginmanager.js Nov 25 21:35:02 pi-poly volumio[853]: - /volumio/app/index.js Nov 25 21:35:02 pi-poly volumio[853]: - /volumio/index.js Nov 25 21:35:02 pi-poly volumio[853]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Nov 25 21:35:02 pi-poly volumio[853]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Nov 25 21:35:02 pi-poly volumio[853]: at Module.require (internal/modules/cjs/loader.js:952:19) Nov 25 21:35:02 pi-poly volumio[853]: at require (internal/modules/cjs/helpers.js:88:18) Nov 25 21:35:02 pi-poly volumio[853]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Nov 25 21:35:02 pi-poly volumio[853]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Nov 25 21:35:02 pi-poly volumio[853]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Nov 25 21:35:02 pi-poly volumio[853]: at Module.load (internal/modules/cjs/loader.js:928:32) Nov 25 21:35:02 pi-poly volumio[853]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Nov 25 21:35:02 pi-poly volumio[853]: at Module.require (internal/modules/cjs/loader.js:952:19) Nov 25 21:35:02 pi-poly volumio[853]: at require (internal/modules/cjs/helpers.js:88:18) Nov 25 21:35:02 pi-poly volumio[853]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Nov 25 21:35:02 pi-poly volumio[853]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 25 21:35:02 pi-poly volumio[853]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 25 21:35:02 pi-poly volumio[853]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 25 21:35:02 pi-poly volumio[853]: error: !!!! WARNING !!!! Nov 25 21:35:02 pi-poly volumio[853]: info: Done. Nov 25 21:35:07 pi-poly volumio[853]: info: Enabling plugin now_playing Nov 25 21:35:07 pi-poly volumio[853]: info: Loading plugin "now_playing"... Nov 25 21:35:07 pi-poly volumio[853]: error: !!!! WARNING !!!! Nov 25 21:35:07 pi-poly volumio[853]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Nov 25 21:35:07 pi-poly volumio[853]: Require stack: Nov 25 21:35:07 pi-poly volumio[853]: - /data/plugins/user_interface/now_playing/dist/index.js Nov 25 21:35:07 pi-poly volumio[853]: - /volumio/app/pluginmanager.js Nov 25 21:35:07 pi-poly volumio[853]: - /volumio/app/index.js Nov 25 21:35:07 pi-poly volumio[853]: - /volumio/index.js Nov 25 21:35:07 pi-poly volumio[853]: error: Stack trace: Error: Cannot find module 'geo-tz' Nov 25 21:35:07 pi-poly volumio[853]: Require stack: Nov 25 21:35:07 pi-poly volumio[853]: - /data/plugins/user_interface/now_playing/dist/index.js Nov 25 21:35:07 pi-poly volumio[853]: - /volumio/app/pluginmanager.js Nov 25 21:35:07 pi-poly volumio[853]: - /volumio/app/index.js Nov 25 21:35:07 pi-poly volumio[853]: - /volumio/index.js Nov 25 21:35:07 pi-poly volumio[853]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Nov 25 21:35:07 pi-poly volumio[853]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Nov 25 21:35:07 pi-poly volumio[853]: at Module.require (internal/modules/cjs/loader.js:952:19) Nov 25 21:35:07 pi-poly volumio[853]: at require (internal/modules/cjs/helpers.js:88:18) Nov 25 21:35:07 pi-poly volumio[853]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Nov 25 21:35:07 pi-poly volumio[853]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Nov 25 21:35:07 pi-poly volumio[853]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Nov 25 21:35:07 pi-poly volumio[853]: at Module.load (internal/modules/cjs/loader.js:928:32) Nov 25 21:35:07 pi-poly volumio[853]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Nov 25 21:35:07 pi-poly volumio[853]: at Module.require (internal/modules/cjs/loader.js:952:19) Nov 25 21:35:07 pi-poly volumio[853]: at require (internal/modules/cjs/helpers.js:88:18) Nov 25 21:35:07 pi-poly volumio[853]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Nov 25 21:35:07 pi-poly volumio[853]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 25 21:35:07 pi-poly volumio[853]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 25 21:35:07 pi-poly volumio[853]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 25 21:35:07 pi-poly volumio[853]: error: !!!! WARNING !!!! Nov 25 21:35:07 pi-poly volumio[853]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Nov 25 21:35:10 pi-poly sudo[5207]: volumio : unable to resolve host pi-poly Nov 25 21:35:10 pi-poly sudo[5207]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:10 pi-poly sudo[5207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop lircd.service Nov 25 21:35:10 pi-poly sudo[5207]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:10 pi-poly lircd[1201]: lircd-0.10.1[1201]: Notice: caught signal Nov 25 21:35:10 pi-poly lircd-0.10.1[1201]: Notice: caught signal Nov 25 21:35:10 pi-poly systemd[1]: Stopping Flexible IR remote input/output application support... Nov 25 21:35:10 pi-poly systemd[1]: lircd.service: Main process exited, code=killed, status=15/TERM Nov 25 21:35:10 pi-poly systemd[1]: lircd.service: Succeeded. Nov 25 21:35:10 pi-poly systemd[1]: Stopped Flexible IR remote input/output application support. Nov 25 21:35:10 pi-poly systemd[1]: irexec.service: Succeeded. Nov 25 21:35:10 pi-poly sudo[5207]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:10 pi-poly volumio[853]: info: ir_controller: systemctl stop lircd.service succeeded. Nov 25 21:35:10 pi-poly volumio[853]: info: Disabling plugin ir_controller Nov 25 21:35:10 pi-poly volumio[853]: info: Done. Nov 25 21:35:10 pi-poly sudo[5212]: volumio : unable to resolve host pi-poly Nov 25 21:35:10 pi-poly sudo[5212]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:10 pi-poly sudo[5212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 0 Nov 25 21:35:10 pi-poly sudo[5212]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:10 pi-poly sudo[5212]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:10 pi-poly volumio[853]: error: ir_controller: Error removing gpio-ir overlay: null Nov 25 21:35:10 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 21:35:10 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 21:35:10 pi-poly volumio[853]: info: Discovery: Getting this device information Nov 25 21:35:10 pi-poly volumio[853]: info: CoreCommandRouter::volumioGetState Nov 25 21:35:10 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 21:35:11 pi-poly volumio[853]: info: Enabling plugin ir_controller Nov 25 21:35:11 pi-poly volumio[853]: info: Loading plugin "ir_controller"... Nov 25 21:35:11 pi-poly volumio[853]: info: Applying required configuration parameters for plugin ir_controller Nov 25 21:35:11 pi-poly volumio[853]: info: PLUGIN START: ir_controller Nov 25 21:35:11 pi-poly volumio[853]: info: Loading i18n strings for locale en Nov 25 21:35:11 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 25 21:35:12 pi-poly sudo[5228]: volumio : unable to resolve host pi-poly Nov 25 21:35:12 pi-poly sudo[5228]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:12 pi-poly sudo[5228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/irexec.lircrc /etc/lirc/lirc_options.conf /etc/lirc/lircd.conf /etc/lirc/lircd.conf.d /etc/lirc/lircmd.conf /etc/lirc/lircrc Nov 25 21:35:12 pi-poly sudo[5228]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:12 pi-poly sudo[5228]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:12 pi-poly volumio[853]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Nov 25 21:35:12 pi-poly volumio[853]: info: ir_controller: LIRC correctly updated. Nov 25 21:35:12 pi-poly volumio[853]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Nov 25 21:35:12 pi-poly volumio[853]: info: Done. Nov 25 21:35:12 pi-poly volumio[853]: info: ir_controller: Raspberry Pi revision code: b03112 Nov 25 21:35:12 pi-poly sudo[5235]: volumio : unable to resolve host pi-poly Nov 25 21:35:12 pi-poly sudo[5235]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:12 pi-poly sudo[5235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Nov 25 21:35:12 pi-poly sudo[5235]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:12 pi-poly sudo[5235]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:12 pi-poly sudo[5242]: volumio : unable to resolve host pi-poly Nov 25 21:35:12 pi-poly sudo[5242]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:12 pi-poly sudo[5242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=18 gpio_pull=up Nov 25 21:35:12 pi-poly sudo[5242]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:12 pi-poly kernel: Registered IR keymap rc-rc6-mce Nov 25 21:35:12 pi-poly kernel: rc rc0: gpio_ir_recv as /devices/platform/ir-receiver@12/rc/rc0 Nov 25 21:35:12 pi-poly kernel: rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Nov 25 21:35:12 pi-poly kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@12/rc/rc0/input19 Nov 25 21:35:12 pi-poly sudo[5242]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:12 pi-poly volumio[853]: error: ir_controller: Error loading overlay: null Nov 25 21:35:12 pi-poly systemd-udevd[5222]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Nov 25 21:35:12 pi-poly systemd-logind[455]: Watching system buttons on /dev/input/event2 (gpio_ir_recv) Nov 25 21:35:13 pi-poly sudo[5256]: volumio : unable to resolve host pi-poly Nov 25 21:35:13 pi-poly sudo[5256]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:13 pi-poly sudo[5256]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Nov 25 21:35:13 pi-poly sudo[5256]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:13 pi-poly systemd[1]: Starting lircd(8) initialization helper tool... Nov 25 21:35:13 pi-poly lircd-setup[5258]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in future versions. Use ConfigParser directly instead. Nov 25 21:35:13 pi-poly lircd-setup[5258]: parser = configparser.SafeConfigParser() Nov 25 21:35:13 pi-poly systemd[1]: lircd-setup.service: Succeeded. Nov 25 21:35:13 pi-poly systemd[1]: Started lircd(8) initialization helper tool. Nov 25 21:35:13 pi-poly systemd[1]: Starting Flexible IR remote input/output application support... Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: lircd: Opening log, level: Info Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Version: lircd 0.10.1 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: System info: Linux pi-poly 6.6.56-v7l+ #1803 SMP Thu Oct 10 14:10:41 BST 2024 armv7l GNU/Linux Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: Initial device: /dev/lirc0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: 'lirc' written to protocols file /sys/class/rc/rc0/protocols Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: Initial device: /dev/lirc0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: [lirc] protocol is enabled Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: driver: default Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: output: /var/run/lirc/lircd Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: nodaemon: 1 Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Info: lircd: Opening log, level: Info Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Notice: Using systemd fd Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Warning: Running as root Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Info: Using remote: lircd.conf. Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: logfile: syslog Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: immediate-init: 0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: permission: 666 Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Notice: lircd(default) ready, using /var/run/lirc/lircd Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: driver-options: Nov 25 21:35:13 pi-poly systemd[1]: Started Flexible IR remote input/output application support. Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: listen: 0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: connect: (null) Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: userelease: 0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: effective_user: (null) Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: release_suffix: _EVUP Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: allow_simulate: 0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: repeat_max: 600 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: configfile: /etc/lirc/lircd.conf Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Options: dynamic_codes: (null) Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Current driver: default Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Driver API version: 3 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Driver version: 0.10.0 Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: lircd: Opening log, level: Info Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: Using systemd fd Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Warning: Running as root Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: Using remote: lircd.conf. Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: lircd(default) ready, using /var/run/lirc/lircd Nov 25 21:35:13 pi-poly sudo[5256]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:13 pi-poly volumio[853]: info: ir_controller: systemctl restart lircd.service succeeded. Nov 25 21:35:13 pi-poly sudo[5263]: volumio : unable to resolve host pi-poly Nov 25 21:35:13 pi-poly sudo[5263]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:13 pi-poly sudo[5263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Nov 25 21:35:13 pi-poly sudo[5263]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 25 21:35:13 pi-poly systemd[1]: Started Handle events from IR remotes decoded by lircd(8). Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Notice: accepted new client on /var/run/lirc/lircd Nov 25 21:35:13 pi-poly lircd[5259]: lircd-0.10.1[5259]: Info: [lirc] protocol is enabled Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Notice: accepted new client on /var/run/lirc/lircd Nov 25 21:35:13 pi-poly lircd-0.10.1[5259]: Info: [lirc] protocol is enabled Nov 25 21:35:13 pi-poly sudo[5263]: pam_unix(sudo:session): session closed for user root Nov 25 21:35:13 pi-poly volumio[853]: info: ir_controller: systemctl restart irexec.service succeeded. Nov 25 21:35:15 pi-poly volumiologrotate[472]: ls: cannot access '/var/log/samba/log.wb-PI': No such file or directory Nov 25 21:35:15 pi-poly volumiologrotate[472]: ls: cannot access 'POLY+': No such file or directory Nov 25 21:35:18 pi-poly volumio[853]: info: Starting Uninstall of plugin user_interface - now_playing Nov 25 21:35:18 pi-poly volumio[853]: info: Uninstalling plugin now_playing Nov 25 21:35:20 pi-poly volumio[853]: info: Enabling plugin now_playing Nov 25 21:35:20 pi-poly volumio[853]: info: Loading plugin "now_playing"... Nov 25 21:35:20 pi-poly volumio[853]: error: !!!! WARNING !!!! Nov 25 21:35:20 pi-poly volumio[853]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Nov 25 21:35:20 pi-poly volumio[853]: Require stack: Nov 25 21:35:20 pi-poly volumio[853]: - /data/plugins/user_interface/now_playing/dist/index.js Nov 25 21:35:20 pi-poly volumio[853]: - /volumio/app/pluginmanager.js Nov 25 21:35:20 pi-poly volumio[853]: - /volumio/app/index.js Nov 25 21:35:20 pi-poly volumio[853]: - /volumio/index.js Nov 25 21:35:20 pi-poly volumio[853]: error: Stack trace: Error: Cannot find module 'geo-tz' Nov 25 21:35:20 pi-poly volumio[853]: Require stack: Nov 25 21:35:20 pi-poly volumio[853]: - /data/plugins/user_interface/now_playing/dist/index.js Nov 25 21:35:20 pi-poly volumio[853]: - /volumio/app/pluginmanager.js Nov 25 21:35:20 pi-poly volumio[853]: - /volumio/app/index.js Nov 25 21:35:20 pi-poly volumio[853]: - /volumio/index.js Nov 25 21:35:20 pi-poly volumio[853]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Nov 25 21:35:20 pi-poly volumio[853]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Nov 25 21:35:20 pi-poly volumio[853]: at Module.require (internal/modules/cjs/loader.js:952:19) Nov 25 21:35:20 pi-poly volumio[853]: at require (internal/modules/cjs/helpers.js:88:18) Nov 25 21:35:20 pi-poly volumio[853]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Nov 25 21:35:20 pi-poly volumio[853]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Nov 25 21:35:20 pi-poly volumio[853]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Nov 25 21:35:20 pi-poly volumio[853]: at Module.load (internal/modules/cjs/loader.js:928:32) Nov 25 21:35:20 pi-poly volumio[853]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Nov 25 21:35:20 pi-poly volumio[853]: at Module.require (internal/modules/cjs/loader.js:952:19) Nov 25 21:35:20 pi-poly volumio[853]: at require (internal/modules/cjs/helpers.js:88:18) Nov 25 21:35:20 pi-poly volumio[853]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Nov 25 21:35:20 pi-poly volumio[853]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 25 21:35:20 pi-poly volumio[853]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 25 21:35:20 pi-poly volumio[853]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 25 21:35:20 pi-poly volumio[853]: error: !!!! WARNING !!!! Nov 25 21:35:20 pi-poly volumio[853]: info: Error: TypeError: Cannot read property 'printToastMessage' of null Nov 25 21:35:23 pi-poly volumio[853]: info: Starting Uninstall of plugin user_interface - now_playing Nov 25 21:35:23 pi-poly volumio[853]: info: Uninstalling plugin now_playing Nov 25 21:35:28 pi-poly volumio[853]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 25 21:35:30 pi-poly volumio[853]: info: CALLMETHOD: system_hardware ir_controller saveIROptions [object Object] Nov 25 21:35:30 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: ir_controller , saveIROptions Nov 25 21:35:30 pi-poly volumio[853]: error: Failed callmethod call: TypeError: Cannot read property 'printToastMessage' of null Nov 25 21:35:32 pi-poly volumio[853]: info: CALLMETHOD: system_hardware ir_controller saveGpioOptions [object Object] Nov 25 21:35:32 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: ir_controller , saveGpioOptions Nov 25 21:35:32 pi-poly volumio[853]: error: Failed callmethod call: TypeError: Cannot read property 'printToastMessage' of null Nov 25 21:35:32 pi-poly volumio[853]: info: CALLMETHOD: system_hardware ir_controller saveGpioOptions [object Object] Nov 25 21:35:32 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: ir_controller , saveGpioOptions Nov 25 21:35:32 pi-poly volumio[853]: error: Failed callmethod call: TypeError: Cannot read property 'printToastMessage' of null Nov 25 21:35:40 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 25 21:35:40 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 25 21:35:40 pi-poly volumio[853]: info: Discovery: Getting this device information Nov 25 21:35:40 pi-poly volumio[853]: info: CoreCommandRouter::volumioGetState Nov 25 21:35:40 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 25 21:35:45 pi-poly go-librespot[1156]: time="2024-11-25T21:35:45+05:30" level=debug msg="obtained new client token: AABahoAGuFZ6v1o9GUCZwFZcCPu15PoZXAL3wFf3qZO+zsEBZV9I3zqekxgaaERpoBzan9WHBaCexGenB8Gjx1/UwSffKCW2i1lKIX1N4Gb3z8rG4+pozgw8c5OdAw1EXQ6PHKymjPOTW2fr+sAuGoi+b+kGX45iJWI2fPdCIVcjdPk9p+LS0S4mV471yYCu/fqbGnZz7kbY2OZVIUflb32U4iKX9yTesdPC1zjmCw7aSzTLkf2HogKB+KOy5w==" Nov 25 21:35:45 pi-poly go-librespot[1156]: time="2024-11-25T21:35:45+05:30" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 25 21:35:45 pi-poly go-librespot[1156]: time="2024-11-25T21:35:45+05:30" level=debug msg="completed keyexchange" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="completed challenge" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="authenticated as 31eakw4m2exsmc37mr4oezeaimbu" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="authenticated as 31eakw4m2exsmc37mr4oezeaimbu" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="dealer connection opened" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=info msg="accepted zeroconf user 31eakw4m2exsmc37mr4oezeaimbu from POCO F1" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="autoplay enabled: false" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="received connection id: ZjNlODgzMjgtMDQwMS00ZDZiLWE4NjktYzAzMTViNzQ5MGI3K2RlYWxlcit0Y3A6Ly8wYWM5NDlmNS5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArQTY3QjAwRkMzNjQxMkUyODEzQTJDQjc0MThCRTFEQjM4MEJFOEQxNDBEQzBBODk3MkVCREVDMEFGOUFFOTlCMg==" Nov 25 21:35:46 pi-poly go-librespot[1156]: time="2024-11-25T21:35:46+05:30" level=debug msg="put connect state because NEW_DEVICE" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="handling transfer player command from e5016a15d34d28c4d2d331abb1dfe3015aff2f7a" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="resolved context of track" uri="spotify:album:4YPdbdBWe5V3gBRTgk4Fab" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=trace msg="fetched new page 0 with 6 items (list: 6)" uri="spotify:album:4YPdbdBWe5V3gBRTgk4Fab" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="loading track (paused: false, position: 79349ms)" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=trace msg="emitting websocket event: will_play" Nov 25 21:35:47 pi-poly volumio[853]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:66PtaNyiEpTK8MOsv29peH","play_origin":"playlist"}} Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="selected format OGG_VORBIS_320 (34455a1ed8f5c02a0cfad979f95bd2fe42e87160)" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="requested aes key for file 34455a1ed8f5c02a0cfad979f95bd2fe42e87160, gid: 66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1699" Nov 25 21:35:47 pi-poly go-librespot[1156]: time="2024-11-25T21:35:47+05:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1294" Nov 25 21:35:48 pi-poly go-librespot[1156]: time="2024-11-25T21:35:48+05:30" level=debug msg="fetched first chunk of 18, total size is 8962084 bytes" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:48 pi-poly go-librespot[1156]: time="2024-11-25T21:35:48+05:30" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:49 pi-poly go-librespot[1156]: time="2024-11-25T21:35:49+05:30" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="fetched chunk 9/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="fetched chunk 8/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="fetched chunk 6/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=trace msg="seek to 79349ms (diff: 52ms, samples: 3499290, bytes: 3581522)" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 10068 us, period size = 444 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 49 frames" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="created new output device" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=info msg="loaded track \"Castaway\" (paused: false, position: 79349ms, duration: 198015ms, prefetched: false)" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="fetched chunk 7/17, size: 524288" uri="spotify:track:66PtaNyiEpTK8MOsv29peH" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=trace msg="scheduling prefetch in 88s" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=trace msg="emitting websocket event: metadata" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=trace msg="emitting websocket event: active" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="sending successful reply for dealer request" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 25 21:35:50 pi-poly volumio[853]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:66PtaNyiEpTK8MOsv29peH","name":"Castaway","artist_names":["Grant","Juneau"],"album_name":"Rocket League x Monstercat Vol. 5","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a7edcd126967425fb3d535c4","position":79349,"duration":198015,"release_date":"year:2018 month:11 day:30","track_number":2,"disc_number":1}} Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 25 21:35:50 pi-poly volumio[853]: SPOTIFY: received: {"type":"active","data":null} Nov 25 21:35:50 pi-poly volumio[853]: info: Aligning Spotify Volume to Volumio Volume Nov 25 21:35:50 pi-poly volumio[853]: info: CoreCommandRouter::volumioGetState Nov 25 21:35:50 pi-poly volumio[853]: info: Setting Spotify Volume from Volumio: 94 Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 21:35:50 pi-poly go-librespot[1156]: time="2024-11-25T21:35:50+05:30" level=trace msg="emitting websocket event: playing" Nov 25 21:35:50 pi-poly volumio[853]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:66PtaNyiEpTK8MOsv29peH","play_origin":"playlist"}} Nov 25 21:35:50 pi-poly volumio[853]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 21:35:50 pi-poly volumio[853]: SPOTIFY: {"status":"play","service":"spop","title":"Castaway","artist":"Grant, Juneau","album":"Rocket League x Monstercat Vol. 5","albumart":"https://i.scdn.co/image/ab67616d00001e02a7edcd126967425fb3d535c4","uri":"spotify:track:66PtaNyiEpTK8MOsv29peH","trackType":"spotify","seek":79349,"duration":198,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 25 21:35:50 pi-poly volumio[853]: info: CoreCommandRouter::servicePushState Nov 25 21:35:50 pi-poly volumio[853]: info: CoreStateMachine::pushState Nov 25 21:35:50 pi-poly volumio[853]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 21:35:50 pi-poly volumio[853]: info: CoreCommandRouter::volumioPushState Nov 25 21:35:50 pi-poly volumio[853]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 21:35:50 pi-poly volumio[853]: TypeError: Cannot read property 'pushState' of null Nov 25 21:35:50 pi-poly volumio[853]: at /volumio/app/index.js:327:32 Nov 25 21:35:50 pi-poly volumio[853]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Nov 25 21:35:50 pi-poly volumio[853]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Nov 25 21:35:50 pi-poly volumio[853]: at CoreCommandRouter.volumioPushState (/volumio/app/index.js:325:13) Nov 25 21:35:50 pi-poly volumio[853]: at CoreStateMachine.pushState (/volumio/app/statemachine.js:530:22) Nov 25 21:35:50 pi-poly volumio[853]: at CoreStateMachine.syncState (/volumio/app/statemachine.js:591:10) Nov 25 21:35:50 pi-poly volumio[853]: at CoreCommandRouter.servicePushState (/volumio/app/index.js:415:28) Nov 25 21:35:50 pi-poly volumio[853]: at ControllerSpotify.pushState (/data/plugins/music_service/spop/index.js:430:31) Nov 25 21:35:50 pi-poly volumio[853]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:320:14) Nov 25 21:35:50 pi-poly volumio[853]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Nov 25 21:35:50 pi-poly volumio[853]: at WebSocket.emit (events.js:315:20) Nov 25 21:35:50 pi-poly volumio[853]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Nov 25 21:35:50 pi-poly volumio[853]: at Receiver.emit (events.js:315:20) Nov 25 21:35:50 pi-poly volumio[853]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Nov 25 21:35:50 pi-poly volumio[853]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Nov 25 21:35:50 pi-poly volumio[853]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Nov 25 21:35:50 pi-poly volumio[853]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 21:35:51 pi-poly sudo[5389]: volumio : unable to resolve host pi-poly Nov 25 21:35:51 pi-poly sudo[5389]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Nov 25 21:35:51 pi-poly sudo[5389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-25 21:34 Nov 25 21:35:51 pi-poly sudo[5389]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"