+- Moode Forum (https://moodeaudio.org/forum)
+-- Forum: moOde audio player (https://moodeaudio.org/forum/forumdisplay.php?fid=3)
+--- Forum: Support (https://moodeaudio.org/forum/forumdisplay.php?fid=7)
+--- Thread: [PROBLEM] Bootup/shutdown issues, how to debug (/showthread.php?tid=3709)
Pages:
1
2
RE: Bootup/shutdown issues, how to debug - Max Schmeling - 04-13-2021
Just to confirm: If I enable Bluetooth, I can't shut down moode from the GUI, only by issuing "shutdown -P now" over ssh. Also I cant enter settings. Both works if I do not enable Bluetooth.
Any ideas??
RE: Bootup/shutdown issues, how to debug - TheOldPresbyope - 04-13-2021
(04-13-2021, 02:13 PM)Max Schmeling Wrote: Just to confirm: If I enable Bluetooth, I can't shut down moode from the GUI, only by issuing "shutdown -P now" over ssh. Also I cant enter settings. Both works if I do not enable Bluetooth.
Any ideas??
This does not happen with a stock moOde installation and suggests you have made significant changes. You have to be more forthcoming about what is different about your system and, specifically, what code changes you made to any file.
As for the slow shutdown issue you began with, the moode.log and message files are unlikely to be helpful.
One thing you could try is to run the following command just before you shutoff the system and then review the resulting file after you reboot to see if there are any longish time steps.
Code:
tail -f /var/log/syslog > syslog.shutdown &I've tried this with and without bluetooth renderer enabled. I've tried it with restarting from the moOde menu and rebooting from the command line. The specifics of the output vary a lot, both because Linux manages its processes asynchronously and because of the difference in the restart method, but the overriding theme is that every time step in the log is very short.
Regards,
Kent
RE: Bootup/shutdown issues, how to debug - vinnn - 04-13-2021
(04-13-2021, 01:14 PM)Max Schmeling Wrote: Strange. I agree, the logs look like startup logs upon closer inspection, but the logs have been taken at the exact time, I shut down the system.
It doesn't seem that I have any issues with boot, but shutdown, especially after I enable Bluetooth. How can I debug the shutdown process? and how can I debug the "Bluetooth issue"? when I enable Bluetooth, I can't shut down from the moode GUI, only by issuing "shutdown -P now" over ssh.
Firstly I'd rule out any possible web browser issues by deleting your browser's cache and try again and also try a different web browser.
If this behaviour persists across browsers then there may be some filesystem corruption affecting certain files and causing the flushing of the fs cache to hang on shutdown. You say you have some sort of power switch attached to the Pi, if you're in the habit of hard powering-off the Pi without shutting it down you can expect filesystem corruption eventually.
Secondly, try a new install on a different SD card if you have one handy.
For looking at shutdown logs the system journal is not persistent by default on RaspiOS and in turn Moode so any journals are gone after shutdown/reboot.
You can change this by setting the journald storage to persistent in /etc/systemd/journald.conf, for example...
Code:
sudo sed -i 's/^#Storage=.*/Storage=persistent/' /etc/systemd/journald.conf
sudo reboot... rebooting to take effect, subsequent shutdowns & reboots are then kept in the system journal.
To put it back...
Code:
sudo sed -i 's/^Storage=.*/Storage=volatile/' /etc/systemd/journald.conf
sudo rebootTo view system journals use the journalctl command, e.g.
Code:
sudo journalctl --list-boots #shows times of previous boots and the boot number
sudo journalctl -b -1 #shows logs from previous boot
sudo journalctl -e #skips to the end of the system messages (aka syslog)
sudo journalctl -ek #skips to the end of kernel messagesYou should then be able to see the shutdown messages in the journal for the previous boot.
At a guess it's something unique to your install or the web browser as described above.
RE: Bootup/shutdown issues, how to debug - TheOldPresbyope - 04-13-2021
What @vinnn said.
Definitely a more disciplined approach than I suggested
Regards,
Kent
RE: Bootup/shutdown issues, how to debug - Max Schmeling - 04-14-2021
First of all, thank you for the suggestions. They are very much appreciated.
Firstly I should probably explain the "modifications" to my moode setup. Basically I use a custom PSU for the Rpi, that using a one button solution can hold the power for the Rpi, and turn it off after shutdown, after a specific time, depending on the value of a capacitor, that discharges, and is kept charged by the output of one of the GPIO pins. When the Rpi shuts down, the GPIO's loose power, making the capacitor discharge, eventually killing the power to the Rpi. The method is somewhat similar to this post http://moodeaudio.org/forum/showthread.php?tid=3627 post#5, except it does not use the dtoverlay technique in config.txt. I have attached the schematics and the code (ampcontroller.zip) for making it work.
In order for code to work, I make the following alterations to the moode installation:
Install python-mpd and python GPIO support (the last one is already installed on moode now)
Code:
Pip3 install python-mpd2
Pip3 install RPi.GPIOin /etc/rc.local the following line is added:
Code:
python /home/pi/ampcontroller.pyBasically that is it.
Just to take one thing at a time, I tried this firstly
Code:
tail -f /var/log/syslog > syslog.shutdown &which produced this:
Code:
root@moode:/var/log# cat syslog
Apr 14 08:26:57 moode rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="338" x-info="https://www.rsyslog.com"] rsyslogd was HUPed
Apr 14 08:26:57 moode systemd[1]: logrotate.service: Succeeded.
Apr 14 08:26:57 moode systemd[1]: Started Rotate log files.
Apr 14 08:26:58 moode systemd[1]: man-db.service: Succeeded.
Apr 14 08:26:58 moode systemd[1]: Started Daily man-db regeneration.
Apr 14 08:26:59 moode kernel: [ 39.673246] Under-voltage detected! (0x00050005)
Apr 14 08:27:02 moode nmbd[482]: [2021/04/14 08:27:02.609800, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Apr 14 08:27:02 moode nmbd[482]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.50 for name WORKGROUP<1d>.
Apr 14 08:27:02 moode nmbd[482]: This response was from IP 10.0.0.200, reporting an IP address of 10.0.0.200.
Apr 14 08:27:03 moode kernel: [ 43.833217] Voltage normalised (0x00000000)
Apr 14 08:27:20 moode systemd[1]: systemd-hostnamed.service: Succeeded.
Apr 14 08:32:12 moode nmbd[482]: [2021/04/14 08:32:12.937316, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Apr 14 08:32:12 moode nmbd[482]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.50 for name WORKGROUP<1d>.
Apr 14 08:32:12 moode nmbd[482]: This response was from IP 10.0.0.200, reporting an IP address of 10.0.0.200.
Apr 14 08:33:58 moode systemd[1]: Created slice User Slice of UID 1000.
Apr 14 08:33:58 moode systemd[1]: Starting User Runtime Directory /run/user/1000...
Apr 14 08:33:58 moode systemd[1]: Started User Runtime Directory /run/user/1000.
Apr 14 08:33:58 moode systemd[1]: Starting User Manager for UID 1000...
Apr 14 08:33:58 moode systemd[1869]: Reached target Timers.
Apr 14 08:33:58 moode systemd[1869]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Apr 14 08:33:58 moode systemd[1869]: Listening on GnuPG network certificate management daemon.
Apr 14 08:33:58 moode systemd[1869]: Starting D-Bus User Message Bus Socket.
Apr 14 08:33:58 moode systemd[1869]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Apr 14 08:33:58 moode systemd[1869]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Apr 14 08:33:58 moode systemd[1869]: Reached target Paths.
Apr 14 08:33:58 moode systemd[1869]: Listening on GnuPG cryptographic agent and passphrase cache.
Apr 14 08:33:58 moode systemd[1869]: Listening on D-Bus User Message Bus Socket.
Apr 14 08:33:58 moode systemd[1869]: Reached target Sockets.
Apr 14 08:33:58 moode systemd[1869]: Reached target Basic System.
Apr 14 08:33:58 moode systemd[1869]: Reached target Default.
Apr 14 08:33:58 moode systemd[1869]: Startup finished in 165ms.
Apr 14 08:33:58 moode systemd[1]: Started User Manager for UID 1000.
Apr 14 08:33:58 moode systemd[1]: Started Session 1 of user pi.
Apr 14 08:34:11 moode bluetoothd[820]: Endpoint registered: sender=:1.11 path=/org/bluez/hci0/A2DP/SBC/Sink/3
Apr 14 08:34:14 moode kernel: [ 474.040746] input: 64:7B:CE:E8:AF:FF as /devices/virtual/input/input0
Apr 14 08:34:14 moode systemd[1]: Stopping Music Player Daemon...
Apr 14 08:34:14 moode systemd[1]: mpd.service: Succeeded.
Apr 14 08:34:14 moode systemd[1]: Stopped Music Player Daemon.
Apr 14 08:34:14 moode systemd[1]: Started Music Player Daemon.
Apr 14 08:34:14 moode rc.local[481]: Traceback (most recent call last):
Apr 14 08:34:14 moode rc.local[481]: File "/home/pi/ampcontroller.py", line 196, in <module>
Apr 14 08:34:14 moode rc.local[481]: if Client.status()['state'] == "play": # Playing or Airplay active
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 469, in mpd_command
Apr 14 08:34:14 moode rc.local[481]: return wrapper(self, name, args, callback)
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 532, in _execute
Apr 14 08:34:14 moode rc.local[481]: return retval()
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 454, in command_callback
Apr 14 08:34:14 moode rc.local[481]: res = function(self, self._read_lines())
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 394, in _parse_object
Apr 14 08:34:14 moode rc.local[481]: objs = list(self._parse_objects(lines))
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 240, in _parse_objects
Apr 14 08:34:14 moode rc.local[481]: for key, value in self._parse_pairs(lines):
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 235, in _parse_pairs
Apr 14 08:34:14 moode rc.local[481]: for line in lines:
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 586, in _read_lines
Apr 14 08:34:14 moode rc.local[481]: line = self._read_line()
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 571, in _read_line
Apr 14 08:34:14 moode rc.local[481]: raise ConnectionError("Connection lost while reading line")
Apr 14 08:34:14 moode rc.local[481]: mpd.base.ConnectionError: Connection lost while reading line
Apr 14 08:34:14 moode systemd[1]: rc-local.service: Control process exited, code=exited, status=1/FAILURE
Apr 14 08:34:14 moode systemd[1]: Created slice system-bluealsa\x2daplay.slice.
Apr 14 08:34:14 moode systemd[1]: Started BlueAlsa-Aplay.
Apr 14 08:34:14 moode systemd[1]: rc-local.service: Failed with result 'exit-code'.
Apr 14 08:34:14 moode systemd[1]: Failed to start /etc/rc.local Compatibility.
Apr 14 08:34:14 moode systemd[1]: Started Getty on tty1.
Apr 14 08:34:14 moode systemd[1]: Reached target Login Prompts.
Apr 14 08:34:14 moode systemd[1]: Reached target Multi-User System.
Apr 14 08:34:14 moode systemd[1]: Starting Update UTMP about System Runlevel Changes...
Apr 14 08:34:14 moode systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Apr 14 08:34:14 moode systemd[1]: Started Update UTMP about System Runlevel Changes.
Apr 14 08:34:14 moode systemd[1]: Startup finished in 1.814s (kernel) + 7min 52.526s (userspace) = 7min 54.340s.
Apr 14 08:34:14 moode kernel: [ 474.400362] rpi_firmware_get_throttled: 1 callbacks suppressed
Apr 14 08:34:14 moode kernel: [ 474.400370] Under-voltage detected! (0x00050005)
Apr 14 08:34:14 moode systemd-udevd[1950]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Apr 14 08:34:16 moode bluetoothd[820]: /org/bluez/hci0/dev_64_7B_CE_E8_AF_FF/fd0: fd(19) ready
Apr 14 08:34:20 moode kernel: [ 480.640202] rpi_firmware_get_throttled: 1 callbacks suppressed
Apr 14 08:34:20 moode kernel: [ 480.640209] Voltage normalised (0x00000000)
Apr 14 08:34:45 moode systemd[1]: Stopping BlueAlsa-Aplay...
Apr 14 08:34:45 moode systemd[1]: bluealsa-aplay@64:7B:CE:E8:AF:FF.service: Succeeded.
Apr 14 08:34:45 moode systemd[1]: Stopped BlueAlsa-Aplay.
Apr 14 08:37:07 moode nmbd[482]: [2021/04/14 08:37:07.392082, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Apr 14 08:37:07 moode nmbd[482]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.50 for name WORKGROUP<1d>.
Apr 14 08:37:07 moode nmbd[482]: This response was from IP 10.0.0.200, reporting an IP address of 10.0.0.200.
Apr 14 08:37:42 moode systemd[1]: Unmounting RPC Pipe File System...
Apr 14 08:37:42 moode systemd[1]: Stopped target Multi-User System.
Apr 14 08:37:42 moode systemd[1]: Stopping LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Apr 14 08:37:47 moode fake-hwclock[111]: Wed 14 Apr 06:37:44 UTC 2021
Apr 14 08:37:47 moode systemd-fsck[134]: e2fsck 1.44.5 (15-Dec-2018)
Apr 14 08:37:47 moode systemd-fsck[134]: rootfs: clean, 98978/258048 files, 751903/1024000 blocks
Apr 14 08:37:47 moode systemd[1]: Started File System Check on Root Device.
Apr 14 08:37:47 moode systemd[1]: Starting Remount Root and Kernel File Systems...
Apr 14 08:37:47 moode systemd[1]: Started udev Coldplug all Devices.
Apr 14 08:37:47 moode systemd[1]: Starting Helper to synchronize boot up for ifupdown...
Apr 14 08:37:47 moode systemd[1]: Started Set the console keyboard layout.
Apr 14 08:37:47 moode systemd[1]: Started Helper to synchronize boot up for ifupdown.
Apr 14 08:37:47 moode systemd[1]: Started Remount Root and Kernel File Systems.
Apr 14 08:37:47 moode systemd[1]: Starting Load/Save Random Seed...
Apr 14 08:37:47 moode systemd[1]: Starting Create System Users...
Apr 14 08:37:47 moode systemd[1]: Starting Flush Journal to Persistent Storage...
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Apr 14 08:37:47 moode systemd[1]: Started Load/Save Random Seed.
Apr 14 08:37:47 moode systemd[1]: Started Create System Users.
Apr 14 08:37:47 moode systemd[1]: Started Flush Journal to Persistent Storage.
Apr 14 08:37:47 moode systemd[1]: Starting Create Static Device Nodes in /dev...
Apr 14 08:37:47 moode systemd[1]: Started Create Static Device Nodes in /dev.
Apr 14 08:37:47 moode systemd[1]: Reached target Local File Systems (Pre).
Apr 14 08:37:47 moode systemd[1]: Starting udev Kernel Device Manager...
Apr 14 08:37:47 moode systemd-udevd[149]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Apr 14 08:37:47 moode systemd[1]: Started udev Kernel Device Manager.
Apr 14 08:37:47 moode systemd-udevd[154]: Using default interface naming scheme 'v240'.
Apr 14 08:37:47 moode systemd[1]: Found device /dev/disk/by-partuuid/067e19d7-01.
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Huge Pages File System being skipped.
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Apr 14 08:37:47 moode systemd[1]: Starting File System Check on /dev/disk/by-partuuid/067e19d7-01...
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Apr 14 08:37:47 moode systemd-fsck[270]: fsck.fat 4.1 (2017-01-24)
Apr 14 08:37:47 moode systemd-fsck[270]: /dev/mmcblk0p1: 326 files, 111789/516190 clusters
Apr 14 08:37:47 moode systemd[1]: Started File System Check on /dev/disk/by-partuuid/067e19d7-01.
Apr 14 08:37:47 moode systemd[1]: Mounting /boot...
Apr 14 08:37:47 moode systemd[1]: Mounted /boot.
Apr 14 08:37:47 moode systemd[1]: Reached target Local File Systems.
Apr 14 08:37:47 moode systemd[1]: Starting Preprocess NFS configuration...
Apr 14 08:37:47 moode systemd[1]: Starting Create Volatile Files and Directories...
Apr 14 08:37:47 moode systemd[1]: Starting Raise network interfaces...
Apr 14 08:37:47 moode systemd[1]: Starting Set console font and keymap...
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Apr 14 08:37:47 moode systemd[1]: nfs-config.service: Succeeded.
Apr 14 08:37:47 moode systemd[1]: Started Preprocess NFS configuration.
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
Apr 14 08:37:47 moode systemd[1]: Reached target NFS client services.
Apr 14 08:37:47 moode systemd[1]: Started Set console font and keymap.
Apr 14 08:37:47 moode systemd[1]: Started Create Volatile Files and Directories.
Apr 14 08:37:47 moode kernel: [ 0.000000] Booting Linux on physical CPU 0x0
Apr 14 08:37:47 moode kernel: [ 0.000000] Linux version 5.4.77-v7l+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1371 SMP Tue Nov 17 13:35:27 GMT 2020
Apr 14 08:37:47 moode kernel: [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
Apr 14 08:37:47 moode kernel: [ 0.000000] CPU: div instructions available: patching division code
Apr 14 08:37:47 moode kernel: [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
Apr 14 08:37:47 moode kernel: [ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
Apr 14 08:37:47 moode kernel: [ 0.000000] Memory policy: Data cache writealloc
Apr 14 08:37:47 moode kernel: [ 0.000000] Reserved memory: created CMA memory pool at 0x000000002ac00000, size 64 MiB
Apr 14 08:37:47 moode kernel: [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
Apr 14 08:37:47 moode kernel: [ 0.000000] On node 0 totalpages: 1012736
Apr 14 08:37:47 moode kernel: [ 0.000000] DMA zone: 2304 pages used for memmap
Apr 14 08:37:47 moode kernel: [ 0.000000] DMA zone: 0 pages reserved
Apr 14 08:37:47 moode kernel: [ 0.000000] DMA zone: 196608 pages, LIFO batch:63
Apr 14 08:37:47 moode kernel: [ 0.000000] HighMem zone: 816128 pages, LIFO batch:63
Apr 14 08:37:47 moode kernel: [ 0.000000] percpu: Embedded 20 pages/cpu s49804 r8192 d23924 u81920
Apr 14 08:37:47 moode kernel: [ 0.000000] pcpu-alloc: s49804 r8192 d23924 u81920 alloc=20*4096
Apr 14 08:37:47 moode kernel: [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
Apr 14 08:37:47 moode kernel: [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1010432
Apr 14 08:37:47 moode kernel: [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:44:A8:7F vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 net.ifnames=0 console=ttyS0,115200 console=tty1 root=PARTUUID=067e19d7-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
Apr 14 08:37:47 moode kernel: [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Apr 14 08:37:47 moode kernel: [ 0.000000] software IO TLB: mapped [mem 0x23cc0000-0x27cc0000] (64MB)
Apr 14 08:37:47 moode kernel: [ 0.000000] Memory: 3852596K/4050944K available (10240K kernel code, 739K rwdata, 2816K rodata, 2048K init, 854K bss, 132812K reserved, 65536K cma-reserved, 3264512K highmem)
Apr 14 08:37:47 moode kernel: [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Apr 14 08:37:47 moode kernel: [ 0.000000] ftrace: allocating 31110 entries in 61 pages
Apr 14 08:37:47 moode kernel: [ 0.000000] rcu: Hierarchical RCU implementation.
Apr 14 08:37:47 moode kernel: [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
Apr 14 08:37:47 moode kernel: [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
Apr 14 08:37:47 moode kernel: [ 0.000000] GIC: Using split EOI/Deactivate mode
Apr 14 08:37:47 moode kernel: [ 0.000000] random: get_random_bytes called from start_kernel+0x344/0x518 with crng_init=0
Apr 14 08:37:47 moode kernel: [ 0.000007] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
Apr 14 08:37:47 moode kernel: [ 0.000030] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
Apr 14 08:37:47 moode kernel: [ 0.000110] bcm2835: system timer (irq = 17)
Apr 14 08:37:47 moode kernel: [ 0.000758] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
Apr 14 08:37:47 moode kernel: [ 0.000777] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
Apr 14 08:37:47 moode kernel: [ 0.000797] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
Apr 14 08:37:47 moode kernel: [ 0.000813] Switching to timer-based delay loop, resolution 18ns
Apr 14 08:37:47 moode kernel: [ 0.001052] Console: colour dummy device 80x30
Apr 14 08:37:47 moode kernel: [ 0.001560] printk: console [tty1] enabled
Apr 14 08:37:47 moode kernel: [ 0.001623] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
Apr 14 08:37:47 moode kernel: [ 0.001665] pid_max: default: 32768 minimum: 301
Apr 14 08:37:47 moode kernel: [ 0.001825] LSM: Security Framework initializing
Apr 14 08:37:47 moode kernel: [ 0.002030] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.002072] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.003439] Disabling memory control group subsystem
Apr 14 08:37:47 moode kernel: [ 0.003579] CPU: Testing write buffer coherency: ok
Apr 14 08:37:47 moode kernel: [ 0.004100] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Apr 14 08:37:47 moode kernel: [ 0.005021] Setting up static identity map for 0x200000 - 0x20003c
Apr 14 08:37:47 moode kernel: [ 0.005241] rcu: Hierarchical SRCU implementation.
Apr 14 08:37:47 moode kernel: [ 0.005932] smp: Bringing up secondary CPUs ...
Apr 14 08:37:47 moode kernel: [ 0.007118] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
Apr 14 08:37:47 moode kernel: [ 0.008429] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
Apr 14 08:37:47 moode kernel: [ 0.009683] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
Apr 14 08:37:47 moode kernel: [ 0.009843] smp: Brought up 1 node, 4 CPUs
Apr 14 08:37:47 moode kernel: [ 0.009916] SMP: Total of 4 processors activated (432.00 BogoMIPS).
Apr 14 08:37:47 moode kernel: [ 0.009943] CPU: All CPU(s) started in HYP mode.
Apr 14 08:37:47 moode kernel: [ 0.009967] CPU: Virtualization extensions available.
Apr 14 08:37:47 moode kernel: [ 0.010803] devtmpfs: initialized
Apr 14 08:37:47 moode kernel: [ 0.024559] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
Apr 14 08:37:47 moode kernel: [ 0.024845] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Apr 14 08:37:47 moode kernel: [ 0.024895] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.026881] pinctrl core: initialized pinctrl subsystem
Apr 14 08:37:47 moode kernel: [ 0.027900] NET: Registered protocol family 16
Apr 14 08:37:47 moode kernel: [ 0.031886] DMA: preallocated 1024 KiB pool for atomic coherent allocations
Apr 14 08:37:47 moode kernel: [ 0.032501] audit: initializing netlink subsys (disabled)
Apr 14 08:37:47 moode kernel: [ 0.032770] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1
Apr 14 08:37:47 moode kernel: [ 0.033876] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
Apr 14 08:37:47 moode kernel: [ 0.033912] hw-breakpoint: maximum watchpoint size is 8 bytes.
Apr 14 08:37:47 moode kernel: [ 0.034244] Serial: AMBA PL011 UART driver
Apr 14 08:37:47 moode kernel: [ 0.037903] bcm2835-mbox fe00b880.mailbox: mailbox enabled
Apr 14 08:37:47 moode kernel: [ 0.060826] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-11-17 13:40, variant start
Apr 14 08:37:47 moode kernel: [ 0.070841] raspberrypi-firmware soc:firmware: Firmware hash is 20c430d6cf4343ed95afba07c4735b7c587a4c83
Apr 14 08:37:47 moode kernel: [ 0.124847] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
Apr 14 08:37:47 moode kernel: [ 0.129914] vgaarb: loaded
Apr 14 08:37:47 moode kernel: [ 0.130396] SCSI subsystem initialized
Apr 14 08:37:47 moode kernel: [ 0.130644] usbcore: registered new interface driver usbfs
Apr 14 08:37:47 moode kernel: [ 0.130718] usbcore: registered new interface driver hub
Apr 14 08:37:47 moode kernel: [ 0.130853] usbcore: registered new device driver usb
Apr 14 08:37:47 moode kernel: [ 0.131246] usb_phy_generic phy: phy supply vcc not found, using dummy regulator
Apr 14 08:37:47 moode kernel: [ 0.133102] clocksource: Switched to clocksource arch_sys_counter
Apr 14 08:37:47 moode kernel: [ 0.830466] VFS: Disk quotas dquot_6.6.0
Apr 14 08:37:47 moode kernel: [ 0.830589] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Apr 14 08:37:47 moode kernel: [ 0.830806] FS-Cache: Loaded
Apr 14 08:37:47 moode kernel: [ 0.831014] CacheFiles: Loaded
Apr 14 08:37:47 moode kernel: [ 0.841353] thermal_sys: Registered thermal governor 'step_wise'
Apr 14 08:37:47 moode kernel: [ 0.841716] NET: Registered protocol family 2
Apr 14 08:37:47 moode kernel: [ 0.842474] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.842526] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.842603] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.842686] TCP: Hash tables configured (established 8192 bind 8192)
Apr 14 08:37:47 moode kernel: [ 0.842848] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.842900] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
Apr 14 08:37:47 moode kernel: [ 0.843345] NET: Registered protocol family 1
Apr 14 08:37:47 moode kernel: [ 0.844181] RPC: Registered named UNIX socket transport module.
Apr 14 08:37:47 moode kernel: [ 0.844212] RPC: Registered udp transport module.
Apr 14 08:37:47 moode kernel: [ 0.844237] RPC: Registered tcp transport module.
Apr 14 08:37:47 moode kernel: [ 0.844263] RPC: Registered tcp NFSv4.1 backchannel transport module.
Apr 14 08:37:47 moode kernel: [ 0.844298] PCI: CLS 0 bytes, default 64
Apr 14 08:37:47 moode kernel: [ 0.846221] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
Apr 14 08:37:47 moode kernel: [ 0.848427] Initialise system trusted keyrings
Apr 14 08:37:47 moode kernel: [ 0.848669] workingset: timestamp_bits=14 max_order=20 bucket_order=6
Apr 14 08:37:47 moode kernel: [ 0.859510] FS-Cache: Netfs 'nfs' registered for caching
Apr 14 08:37:47 moode kernel: [ 0.860247] NFS: Registering the id_resolver key type
Apr 14 08:37:47 moode kernel: [ 0.860306] Key type id_resolver registered
Apr 14 08:37:47 moode kernel: [ 0.860332] Key type id_legacy registered
Apr 14 08:37:47 moode kernel: [ 0.860368] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
Apr 14 08:37:47 moode kernel: [ 0.861492] Key type asymmetric registered
Apr 14 08:37:47 moode kernel: [ 0.861521] Asymmetric key parser 'x509' registered
Apr 14 08:37:47 moode kernel: [ 0.861726] bounce: pool size: 64 pages
Apr 14 08:37:47 moode kernel: [ 0.861789] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
Apr 14 08:37:47 moode kernel: [ 0.862032] io scheduler mq-deadline registered
Apr 14 08:37:47 moode kernel: [ 0.862062] io scheduler kyber registered
Apr 14 08:37:47 moode kernel: [ 0.866155] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
Apr 14 08:37:47 moode kernel: [ 0.866199] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
Apr 14 08:37:47 moode kernel: [ 0.866290] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x0603ffffff -> 0x00f8000000
Apr 14 08:37:47 moode kernel: [ 0.866381] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000
Apr 14 08:37:47 moode kernel: [ 0.925252] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)
Apr 14 08:37:47 moode kernel: [ 0.925586] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
Apr 14 08:37:47 moode kernel: [ 0.925621] pci_bus 0000:00: root bus resource [bus 00-ff]
Apr 14 08:37:47 moode kernel: [ 0.925655] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
Apr 14 08:37:47 moode kernel: [ 0.925734] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
Apr 14 08:37:47 moode kernel: [ 0.926019] pci 0000:00:00.0: PME# supported from D0 D3hot
Apr 14 08:37:47 moode kernel: [ 0.929298] PCI: bus0: Fast back to back transfers disabled
Apr 14 08:37:47 moode kernel: [ 0.929544] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
Apr 14 08:37:47 moode kernel: [ 0.929707] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
Apr 14 08:37:47 moode kernel: [ 0.930155] pci 0000:01:00.0: PME# supported from D0 D3cold
Apr 14 08:37:47 moode kernel: [ 0.933446] PCI: bus1: Fast back to back transfers disabled
Apr 14 08:37:47 moode kernel: [ 0.933522] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
Apr 14 08:37:47 moode kernel: [ 0.933562] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
Apr 14 08:37:47 moode kernel: [ 0.933663] pci 0000:00:00.0: PCI bridge to [bus 01]
Apr 14 08:37:47 moode kernel: [ 0.933701] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
Apr 14 08:37:47 moode kernel: [ 0.934031] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
Apr 14 08:37:47 moode kernel: [ 0.934290] pcieport 0000:00:00.0: PME: Signaling with IRQ 54
Apr 14 08:37:47 moode kernel: [ 0.934704] pcieport 0000:00:00.0: AER: enabled with IRQ 54
Apr 14 08:37:47 moode kernel: [ 0.935057] pci 0000:01:00.0: enabling device (0140 -> 0142)
Apr 14 08:37:47 moode kernel: [ 0.935784] bcm2708_fb soc:fb: FB found 1 display(s)
Apr 14 08:37:47 moode kernel: [ 0.946248] Console: switching to colour frame buffer device 80x30
Apr 14 08:37:47 moode kernel: [ 0.949222] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 640x480
Apr 14 08:37:47 moode kernel: [ 0.957614] iproc-rng200 fe104000.rng: hwrng registered
Apr 14 08:37:47 moode kernel: [ 0.958888] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
Apr 14 08:37:47 moode kernel: [ 0.961451] vc-sm: Videocore shared memory driver
Apr 14 08:37:47 moode kernel: [ 0.962986] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
Apr 14 08:37:47 moode kernel: [ 0.977311] brd: module loaded
Apr 14 08:37:47 moode kernel: [ 0.990705] loop: module loaded
Apr 14 08:37:47 moode kernel: [ 0.993076] Loading iSCSI transport class v2.0-870.
Apr 14 08:37:47 moode kernel: [ 0.996153] libphy: Fixed MDIO Bus: probed
Apr 14 08:37:47 moode kernel: [ 0.997727] bcmgenet fd580000.ethernet: failed to get enet clock
Apr 14 08:37:47 moode kernel: [ 0.998705] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
Apr 14 08:37:47 moode kernel: [ 0.999658] bcmgenet fd580000.ethernet: failed to get enet-wol clock
Apr 14 08:37:47 moode kernel: [ 1.000626] bcmgenet fd580000.ethernet: failed to get enet-eee clock
Apr 14 08:37:47 moode kernel: [ 1.001556] bcmgenet: Skipping UMAC reset
Apr 14 08:37:47 moode kernel: [ 1.013156] libphy: bcmgenet MII bus: probed
Apr 14 08:37:47 moode kernel: [ 1.093239] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
Apr 14 08:37:47 moode kernel: [ 1.095153] usbcore: registered new interface driver r8152
Apr 14 08:37:47 moode kernel: [ 1.096137] usbcore: registered new interface driver lan78xx
Apr 14 08:37:47 moode kernel: [ 1.097107] usbcore: registered new interface driver smsc95xx
Apr 14 08:37:47 moode kernel: [ 1.098410] xhci_hcd 0000:01:00.0: xHCI Host Controller
Apr 14 08:37:47 moode kernel: [ 1.099315] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
Apr 14 08:37:47 moode kernel: [ 1.103463] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000003000000890
Apr 14 08:37:47 moode kernel: [ 1.106509] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
Apr 14 08:37:47 moode kernel: [ 1.108279] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Apr 14 08:37:47 moode kernel: [ 1.110074] usb usb1: Product: xHCI Host Controller
Apr 14 08:37:47 moode kernel: [ 1.110979] usb usb1: Manufacturer: Linux 5.4.77-v7l+ xhci-hcd
Apr 14 08:37:47 moode kernel: [ 1.111897] usb usb1: SerialNumber: 0000:01:00.0
Apr 14 08:37:47 moode kernel: [ 1.113523] hub 1-0:1.0: USB hub found
Apr 14 08:37:47 moode kernel: [ 1.114520] hub 1-0:1.0: 1 port detected
Apr 14 08:37:47 moode kernel: [ 1.115973] xhci_hcd 0000:01:00.0: xHCI Host Controller
Apr 14 08:37:47 moode kernel: [ 1.116891] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
Apr 14 08:37:47 moode kernel: [ 1.118702] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
Apr 14 08:37:47 moode kernel: [ 1.120201] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04
Apr 14 08:37:47 moode kernel: [ 1.122159] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Apr 14 08:37:47 moode kernel: [ 1.124213] usb usb2: Product: xHCI Host Controller
Apr 14 08:37:47 moode kernel: [ 1.125271] usb usb2: Manufacturer: Linux 5.4.77-v7l+ xhci-hcd
Apr 14 08:37:47 moode kernel: [ 1.126355] usb usb2: SerialNumber: 0000:01:00.0
Apr 14 08:37:47 moode kernel: [ 1.128017] hub 2-0:1.0: USB hub found
Apr 14 08:37:47 moode kernel: [ 1.129155] hub 2-0:1.0: 4 ports detected
Apr 14 08:37:47 moode kernel: [ 1.131656] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
Apr 14 08:37:47 moode kernel: [ 1.132965] dwc_otg: FIQ enabled
Apr 14 08:37:47 moode kernel: [ 1.132978] dwc_otg: NAK holdoff enabled
Apr 14 08:37:47 moode kernel: [ 1.132990] dwc_otg: FIQ split-transaction FSM enabled
Apr 14 08:37:47 moode kernel: [ 1.133006] Module dwc_common_port init
Apr 14 08:37:47 moode kernel: [ 1.133510] usbcore: registered new interface driver uas
Apr 14 08:37:47 moode kernel: [ 1.134625] usbcore: registered new interface driver usb-storage
Apr 14 08:37:47 moode kernel: [ 1.135789] mousedev: PS/2 mouse device common for all mice
Apr 14 08:37:47 moode kernel: [ 1.138604] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
Apr 14 08:37:47 moode kernel: [ 1.143044] sdhci: Secure Digital Host Controller Interface driver
Apr 14 08:37:47 moode kernel: [ 1.144025] sdhci: Copyright(c) Pierre Ossman
Apr 14 08:37:47 moode kernel: [ 1.145521] sdhci-pltfm: SDHCI platform and OF driver helper
Apr 14 08:37:47 moode kernel: [ 1.149708] ledtrig-cpu: registered to indicate activity on CPUs
Apr 14 08:37:47 moode kernel: [ 1.150969] hidraw: raw HID events driver (C) Jiri Kosina
Apr 14 08:37:47 moode kernel: [ 1.152102] usbcore: registered new interface driver usbhid
Apr 14 08:37:47 moode kernel: [ 1.153075] usbhid: USB HID core driver
Apr 14 08:37:47 moode kernel: [ 1.155173] vchiq: vchiq_init_state: slot_zero = (ptrval)
Apr 14 08:37:47 moode kernel: [ 1.158133] [vc_sm_connected_init]: start
Apr 14 08:37:47 moode kernel: [ 1.167337] [vc_sm_connected_init]: end - returning 0
Apr 14 08:37:47 moode kernel: [ 1.170206] Initializing XFRM netlink socket
Apr 14 08:37:47 moode kernel: [ 1.171141] NET: Registered protocol family 17
Apr 14 08:37:47 moode kernel: [ 1.172131] Key type dns_resolver registered
Apr 14 08:37:47 moode kernel: [ 1.173415] Registering SWP/SWPB emulation handler
Apr 14 08:37:47 moode kernel: [ 1.174599] registered taskstats version 1
Apr 14 08:37:47 moode kernel: [ 1.175430] Loading compiled-in X.509 certificates
Apr 14 08:37:47 moode kernel: [ 1.176783] Key type ._fscrypt registered
Apr 14 08:37:47 moode kernel: [ 1.177606] Key type .fscrypt registered
Apr 14 08:37:47 moode kernel: [ 1.189144] uart-pl011 fe201000.serial: cts_event_workaround enabled
Apr 14 08:37:47 moode kernel: [ 1.190076] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 29, base_baud = 0) is a PL011 rev2
Apr 14 08:37:47 moode kernel: [ 1.197884] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
Apr 14 08:37:47 moode kernel: [ 1.236048] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
Apr 14 08:37:47 moode kernel: [ 1.241020] of_cfs_init
Apr 14 08:37:47 moode kernel: [ 1.242040] of_cfs_init: OK
Apr 14 08:37:47 moode kernel: [ 1.243979] Waiting for root device PARTUUID=067e19d7-02...
Apr 14 08:37:47 moode kernel: [ 1.349330] mmc0: new ultra high speed DDR50 SDHC card at address e624
Apr 14 08:37:47 moode kernel: [ 1.351202] mmcblk0: mmc0:e624 SR32G 29.7 GiB
Apr 14 08:37:47 moode kernel: [ 1.354224] mmcblk0: p1 p2
Apr 14 08:37:47 moode kernel: [ 1.371383] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Apr 14 08:37:47 moode kernel: [ 1.373318] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Apr 14 08:37:47 moode kernel: [ 1.379401] devtmpfs: mounted
Apr 14 08:37:47 moode kernel: [ 1.389060] Freeing unused kernel memory: 2048K
Apr 14 08:37:47 moode kernel: [ 1.413414] Run /sbin/init as init process
Apr 14 08:37:47 moode kernel: [ 1.483175] usb 1-1: new high-speed USB device number 2 using xhci_hcd
Apr 14 08:37:47 moode kernel: [ 1.509272] random: fast init done
Apr 14 08:37:47 moode kernel: [ 1.666352] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
Apr 14 08:37:47 moode kernel: [ 1.668452] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Apr 14 08:37:47 moode kernel: [ 1.669561] usb 1-1: Product: USB2.0 Hub
Apr 14 08:37:47 moode kernel: [ 1.673013] hub 1-1:1.0: USB hub found
Apr 14 08:37:47 moode kernel: [ 1.674405] hub 1-1:1.0: 4 ports detected
Apr 14 08:37:47 moode kernel: [ 1.948172] NET: Registered protocol family 10
Apr 14 08:37:47 moode kernel: [ 1.950557] Segment Routing with IPv6
Apr 14 08:37:47 moode systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Apr 14 08:37:47 moode systemd[1]: Starting Network Time Synchronization...
Apr 14 08:37:47 moode systemd[1]: Starting RPC bind portmap service...
Apr 14 08:37:47 moode systemd[1]: Started Entropy daemon using the HAVEGE algorithm.
Apr 14 08:37:47 moode systemd[1]: Started Update UTMP about System Boot/Shutdown.
Apr 14 08:37:47 moode systemd[1]: Started RPC bind portmap service.
Apr 14 08:37:47 moode systemd[1]: Reached target RPC Port Mapper.
Apr 14 08:37:47 moode systemd[1]: Reached target Remote File Systems (Pre).
Apr 14 08:37:47 moode systemd[1]: Reached target Remote File Systems.
Apr 14 08:37:47 moode systemd[1]: Started Raise network interfaces.
Apr 14 08:37:47 moode systemd[1]: Started Network Time Synchronization.
Apr 14 08:37:47 moode systemd[1]: Reached target System Time Synchronized.
Apr 14 08:37:47 moode systemd[1]: Reached target System Initialization.
Apr 14 08:37:47 moode systemd[1]: Listening on D-Bus System Message Bus Socket.
Apr 14 08:37:47 moode systemd[1]: Started Daily Cleanup of Temporary Directories.
Apr 14 08:37:47 moode systemd[1]: Started Daily rotation of log files.
Apr 14 08:37:47 moode systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Apr 14 08:37:47 moode systemd[1]: Listening on triggerhappy.socket.
Apr 14 08:37:47 moode systemd[1]: Reached target Sockets.
Apr 14 08:37:47 moode systemd[1]: Reached target Basic System.
Apr 14 08:37:47 moode systemd[1]: Starting System Logging Service...
Apr 14 08:37:47 moode systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
Apr 14 08:37:47 moode systemd[1]: Starting Resets System Activity Data Collector...
Apr 14 08:37:47 moode systemd[1]: Started D-Bus System Message Bus.
Apr 14 08:37:47 moode systemd[1]: Starting WPA supplicant...
Apr 14 08:37:47 moode systemd[1]: Starting Login Service...
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped.
Apr 14 08:37:47 moode rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.1901.0]
Apr 14 08:37:47 moode rsyslogd: [origin software="rsyslogd" swVersion="8.1901.0" x-pid="337" x-info="https://www.rsyslog.com"] start
Apr 14 08:37:47 moode systemd[1]: Started Manage Sound Card State (restore and store).
Apr 14 08:37:47 moode kernel: [ 2.612773] random: systemd: uninitialized urandom read (16 bytes read)
Apr 14 08:37:47 moode kernel: [ 2.763339] random: systemd: uninitialized urandom read (16 bytes read)
Apr 14 08:37:47 moode kernel: [ 2.768921] random: systemd: uninitialized urandom read (16 bytes read)
Apr 14 08:37:47 moode kernel: [ 3.435655] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Apr 14 08:37:47 moode kernel: [ 4.269464] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
Apr 14 08:37:47 moode kernel: [ 4.270604] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
Apr 14 08:37:47 moode kernel: [ 4.271035] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
Apr 14 08:37:47 moode kernel: [ 4.271477] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
Apr 14 08:37:47 moode kernel: [ 4.279075] snd-rpi-simple soc:sound: ASoC: failed to init link RPi-DAC: -517
Apr 14 08:37:47 moode kernel: [ 4.279211] snd_soc_pcm1794a: loading out-of-tree module taints kernel.
Apr 14 08:37:47 moode kernel: [ 4.280342] snd-rpi-simple soc:sound: ASoC: failed to init link RPi-DAC: -517
Apr 14 08:37:47 moode kernel: [ 4.286549] snd-rpi-simple soc:sound: pcm1794a-codec <-> fe203000.i2s mapping ok
Apr 14 08:37:47 moode kernel: [ 4.295302] mc: Linux media interface: v0.10
Apr 14 08:37:47 moode kernel: [ 4.298157] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
Apr 14 08:37:47 moode kernel: [ 4.319022] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
Apr 14 08:37:47 moode kernel: [ 4.319044] [vc_sm_connected_init]: start
Apr 14 08:37:47 moode kernel: [ 4.347670] [vc_sm_connected_init]: installed successfully
Apr 14 08:37:47 moode kernel: [ 4.399755] videodev: Linux video capture interface: v2.00
Apr 14 08:37:47 moode kernel: [ 4.419595] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Apr 14 08:37:47 moode kernel: [ 4.419610] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Apr 14 08:37:47 moode kernel: [ 4.426817] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
Apr 14 08:37:47 moode kernel: [ 4.440161] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
Apr 14 08:37:47 moode kernel: [ 4.493230] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
Apr 14 08:37:47 moode kernel: [ 4.504861] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
Apr 14 08:37:47 moode kernel: [ 4.505404] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
Apr 14 08:37:47 moode kernel: [ 4.505924] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
Apr 14 08:37:47 moode kernel: [ 4.506777] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
Apr 14 08:37:47 moode kernel: [ 4.506805] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
Apr 14 08:37:47 moode kernel: [ 4.506828] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
Apr 14 08:37:47 moode kernel: [ 4.506848] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
Apr 14 08:37:47 moode kernel: [ 4.506868] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
Apr 14 08:37:47 moode kernel: [ 4.507054] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
Apr 14 08:37:47 moode kernel: [ 4.531540] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
Apr 14 08:37:47 moode kernel: [ 4.531605] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
Apr 14 08:37:47 moode kernel: [ 4.545290] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
Apr 14 08:37:47 moode kernel: [ 4.545332] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
Apr 14 08:37:47 moode kernel: [ 4.563959] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
Apr 14 08:37:47 moode kernel: [ 4.564000] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
Apr 14 08:37:47 moode alsactl[348]: alsactl 1.1.8 daemon started
Apr 14 08:37:47 moode systemd[1]: Starting Save/Restore Sound Card State...
Apr 14 08:37:47 moode systemd[1]: Starting rng-tools.service...
Apr 14 08:37:47 moode systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Apr 14 08:37:47 moode systemd[1]: Starting Check for Raspberry Pi EEPROM updates...
Apr 14 08:37:47 moode systemd[1]: Starting dhcpcd on all interfaces...
Apr 14 08:37:47 moode systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Apr 14 08:37:47 moode systemd[1]: Started Daily man-db regeneration.
Apr 14 08:37:47 moode systemd[1]: Reached target Timers.
Apr 14 08:37:47 moode rngd[357]: rngd 2-unofficial-mt.14 starting up...
Apr 14 08:37:47 moode systemd[1]: Started System Logging Service.
Apr 14 08:37:47 moode rng-tools[350]: Starting Hardware RNG entropy gatherer daemon: rngd.
Apr 14 08:37:47 moode systemd[1]: Started Resets System Activity Data Collector.
Apr 14 08:37:47 moode systemd[1]: Started Save/Restore Sound Card State.
Apr 14 08:37:47 moode systemd[1]: Started rng-tools.service.
Apr 14 08:37:47 moode avahi-daemon[352]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113).
Apr 14 08:37:47 moode avahi-daemon[352]: Successfully dropped root privileges.
Apr 14 08:37:47 moode avahi-daemon[352]: avahi-daemon 0.7 starting up.
Apr 14 08:37:47 moode systemd[1]: Reached target Sound Card.
Apr 14 08:37:47 moode dbus-daemon[341]: [system] Successfully activated service 'org.freedesktop.systemd1'
Apr 14 08:37:47 moode wpa_supplicant[343]: Successfully initialized wpa_supplicant
Apr 14 08:37:47 moode kernel: [ 6.834991] random: crng init done
Apr 14 08:37:47 moode kernel: [ 6.835008] random: 7 urandom warning(s) missed due to ratelimiting
Apr 14 08:37:47 moode rngd[357]: entropy feed to the kernel ready
Apr 14 08:37:47 moode rpi-eeprom-update[353]: BCM2711 detected
Apr 14 08:37:47 moode rpi-eeprom-update[353]: Dedicated VL805 EEPROM detected
Apr 14 08:37:47 moode dhcpcd[354]: dev: loaded udev
Apr 14 08:37:47 moode avahi-daemon[352]: Successfully called chroot().
Apr 14 08:37:47 moode systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Apr 14 08:37:47 moode avahi-daemon[352]: Successfully dropped remaining capabilities.
Apr 14 08:37:47 moode avahi-daemon[352]: Loading service file /services/moode.service.
Apr 14 08:37:47 moode systemd[1]: Started Login Service.
Apr 14 08:37:47 moode avahi-daemon[352]: Loading service file /services/samba.service.
Apr 14 08:37:47 moode systemd[1]: Started WPA supplicant.
Apr 14 08:37:47 moode avahi-daemon[352]: Loading service file /services/udisks.service.
Apr 14 08:37:47 moode avahi-daemon[352]: Network interface enumeration completed.
Apr 14 08:37:47 moode avahi-daemon[352]: Server startup complete. Host name is moode.local. Local service cookie is 568216026.
Apr 14 08:37:47 moode avahi-daemon[352]: Service "moode" (/services/udisks.service) successfully established.
Apr 14 08:37:47 moode avahi-daemon[352]: Service "moode" (/services/samba.service) successfully established.
Apr 14 08:37:47 moode avahi-daemon[352]: Service "moOde audio player: moode" (/services/moode.service) successfully established.
Apr 14 08:37:47 moode kernel: [ 6.902732] 8021q: 802.1Q VLAN Support v1.8
Apr 14 08:37:47 moode raspi-config[338]: Checking if shift key is held down:Error opening '/dev/input/event*': No such file or directory
Apr 14 08:37:47 moode raspi-config[338]: No. Switching to ondemand scaling governor.
Apr 14 08:37:47 moode systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Apr 14 08:37:47 moode systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
Apr 14 08:37:47 moode kernel: [ 6.978926] cfg80211: Loading compiled-in X.509 certificates for regulatory database
Apr 14 08:37:48 moode kernel: [ 7.014414] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
Apr 14 08:37:48 moode dhcpcd[354]: eth0: waiting for carrier
Apr 14 08:37:48 moode kernel: [ 7.055563] bcmgenet: Skipping UMAC reset
Apr 14 08:37:48 moode kernel: [ 7.057340] bcmgenet fd580000.ethernet: configuring instance for external RGMII
Apr 14 08:37:48 moode kernel: [ 7.057865] bcmgenet fd580000.ethernet eth0: Link is Down
Apr 14 08:37:48 moode rpi-eeprom-update[353]: BOOTLOADER: up-to-date
Apr 14 08:37:48 moode rpi-eeprom-update[353]: CURRENT: Thu 3 Sep 12:11:43 UTC 2020 (1599135103)
Apr 14 08:37:48 moode rpi-eeprom-update[353]: LATEST: Thu 3 Sep 12:11:43 UTC 2020 (1599135103)
Apr 14 08:37:48 moode rpi-eeprom-update[353]: FW DIR: /lib/firmware/raspberrypi/bootloader/critical
Apr 14 08:37:48 moode rpi-eeprom-update[353]: VL805: up-to-date
Apr 14 08:37:48 moode rpi-eeprom-update[353]: CURRENT: 000138a1
Apr 14 08:37:48 moode rpi-eeprom-update[353]: LATEST: 000138a1
Apr 14 08:37:48 moode systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Apr 14 08:37:48 moode haveged[301]: haveged: ver: 1.9.1; arch: generic; vend: ; build: (gcc 8.2.0 CTV); collect: 128K
Apr 14 08:37:48 moode haveged[301]: haveged: cpu: (VC); data: 16K (D); inst: 16K (D); idx: 11/40; sz: 14768/63488
Apr 14 08:37:48 moode haveged[301]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B): last entropy estimate 7.99888
Apr 14 08:37:48 moode haveged[301]: haveged: fills: 0, generated: 0
Apr 14 08:37:53 moode dhcpcd[354]: eth0: carrier acquired
Apr 14 08:37:53 moode kernel: [ 12.233357] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Apr 14 08:37:53 moode kernel: [ 12.233408] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Apr 14 08:37:53 moode dhcpcd[354]: DUID 00:01:00:01:27:e5:2b:79:dc:a6:32:44:a8:7f
Apr 14 08:37:53 moode dhcpcd[354]: eth0: IAID 32:44:a8:7f
Apr 14 08:37:53 moode dhcpcd[354]: eth0: adding address fe80::acbe:be41:93d7:8ad
Apr 14 08:37:53 moode avahi-daemon[352]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::acbe:be41:93d7:8ad.
Apr 14 08:37:53 moode avahi-daemon[352]: New relevant interface eth0.IPv6 for mDNS.
Apr 14 08:37:53 moode avahi-daemon[352]: Registering new address record for fe80::acbe:be41:93d7:8ad on eth0.*.
Apr 14 08:37:53 moode dhcpcd[354]: eth0: rebinding lease of 10.0.0.50
Apr 14 08:37:53 moode dhcpcd[354]: eth0: soliciting an IPv6 router
Apr 14 08:37:53 moode dhcpcd[354]: eth0: probing address 10.0.0.50/24
Apr 14 08:37:59 moode dhcpcd[354]: eth0: leased 10.0.0.50 for 86400 seconds
Apr 14 08:37:59 moode dhcpcd[354]: eth0: adding route to 10.0.0.0/24
Apr 14 08:37:59 moode avahi-daemon[352]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.0.0.50.
Apr 14 08:37:59 moode dhcpcd[354]: eth0: adding default route via 10.0.0.1
Apr 14 08:37:59 moode avahi-daemon[352]: New relevant interface eth0.IPv4 for mDNS.
Apr 14 08:37:59 moode avahi-daemon[352]: Registering new address record for 10.0.0.50 on eth0.IPv4.
Apr 14 08:37:59 moode dhcpcd[354]: forked to background, child pid 477
Apr 14 08:37:59 moode systemd[1]: Started dhcpcd on all interfaces.
Apr 14 08:37:59 moode systemd[1]: Reached target Network.
Apr 14 08:37:59 moode systemd[1]: Reached target Network is Online.
Apr 14 08:37:59 moode systemd[1]: Starting A high performance web server and a reverse proxy server...
Apr 14 08:37:59 moode systemd[1]: Starting Samba NMB Daemon...
Apr 14 08:37:59 moode systemd[1]: Starting OpenBSD Secure Shell server...
Apr 14 08:37:59 moode systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Apr 14 08:37:59 moode systemd[1]: Starting Permit User Sessions...
Apr 14 08:37:59 moode systemd[1]: Starting /etc/rc.local Compatibility...
Apr 14 08:37:59 moode systemd[1]: Starting The PHP 7.3 FastCGI Process Manager...
Apr 14 08:37:59 moode systemd[1]: Started Permit User Sessions.
Apr 14 08:37:59 moode rfkill: unblock set for type wifi
Apr 14 08:37:59 moode systemd[1]: Started OpenBSD Secure Shell server.
Apr 14 08:37:59 moode dbus-daemon[341]: [system] Activating via systemd: service name='org.freedesktop.UDisks' unit='udisks.service' requested by ':1.6' (uid=0 pid=491 comm="/usr/bin/udisks-glue --config=/etc/udisks-glue.con")
Apr 14 08:37:59 moode systemd[1]: Starting Disk Manager (legacy version)...
Apr 14 08:37:59 moode dbus-daemon[341]: [system] Successfully activated service 'org.freedesktop.UDisks'
Apr 14 08:37:59 moode systemd[1]: Started Disk Manager (legacy version).
Apr 14 08:37:59 moode dbus-daemon[341]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.8' (uid=0 pid=495 comm="/usr/lib/udisks/udisks-daemon --no-debug ")
Apr 14 08:37:59 moode systemd[1]: Starting Authorization Manager...
Apr 14 08:37:59 moode polkitd[499]: started daemon version 0.105 using authority implementation `local' version `0.105'
Apr 14 08:37:59 moode dbus-daemon[341]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Apr 14 08:37:59 moode systemd[1]: Started Authorization Manager.
Apr 14 08:38:00 moode systemd[1]: Started A high performance web server and a reverse proxy server.
Apr 14 08:38:00 moode systemd[1]: Started The PHP 7.3 FastCGI Process Manager.
Apr 14 08:38:00 moode systemd[1]: Started Samba NMB Daemon.
Apr 14 08:38:00 moode nmbd[479]: [2021/04/14 08:38:00.374633, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 14 08:38:00 moode nmbd[479]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections
Apr 14 08:38:00 moode nmbd[479]: [2021/04/14 08:38:00.379346, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Apr 14 08:38:00 moode nmbd[479]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.50 for name WORKGROUP<1d>.
Apr 14 08:38:00 moode nmbd[479]: This response was from IP 10.0.0.200, reporting an IP address of 10.0.0.200.
Apr 14 08:38:00 moode systemd[1]: Starting Samba Winbind Daemon...
Apr 14 08:38:00 moode winbindd[513]: [2021/04/14 08:38:00.666096, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache)
Apr 14 08:38:00 moode winbindd[513]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
Apr 14 08:38:00 moode winbindd[513]: [2021/04/14 08:38:00.700614, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 14 08:38:00 moode winbindd[513]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections
Apr 14 08:38:00 moode systemd[1]: Started Samba Winbind Daemon.
Apr 14 08:38:00 moode systemd[1]: Starting Samba SMB Daemon...
Apr 14 08:38:01 moode systemd[1]: Started Samba SMB Daemon.
Apr 14 08:38:01 moode smbd[531]: [2021/04/14 08:38:01.189205, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 14 08:38:01 moode smbd[531]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
Apr 14 08:38:04 moode systemd[1]: Started Music Player Daemon.
Apr 14 08:38:04 moode systemd[1]: Starting Configure Bluetooth Modems connected by UART...
Apr 14 08:38:04 moode kernel: [ 23.995154] uart-pl011 fe201000.serial: no DMA platform data
Apr 14 08:38:06 moode kernel: [ 25.033310] Under-voltage detected! (0x00050005)
Apr 14 08:38:06 moode dhcpcd[477]: eth0: no IPv6 Routers available
Apr 14 08:38:10 moode kernel: [ 29.193220] Voltage normalised (0x00000000)
Apr 14 08:38:11 moode kernel: [ 30.680289] Bluetooth: Core ver 2.22
Apr 14 08:38:11 moode kernel: [ 30.680366] NET: Registered protocol family 31
Apr 14 08:38:11 moode kernel: [ 30.680378] Bluetooth: HCI device and connection manager initialized
Apr 14 08:38:11 moode kernel: [ 30.680411] Bluetooth: HCI socket layer initialized
Apr 14 08:38:11 moode kernel: [ 30.680429] Bluetooth: L2CAP socket layer initialized
Apr 14 08:38:11 moode kernel: [ 30.680456] Bluetooth: SCO socket layer initialized
Apr 14 08:38:11 moode kernel: [ 30.689864] Bluetooth: HCI UART driver ver 2.3
Apr 14 08:38:11 moode kernel: [ 30.689881] Bluetooth: HCI UART protocol H4 registered
Apr 14 08:38:11 moode kernel: [ 30.689955] Bluetooth: HCI UART protocol Three-wire (H5) registered
Apr 14 08:38:11 moode kernel: [ 30.690231] Bluetooth: HCI UART protocol Broadcom registered
Apr 14 08:38:11 moode systemd[1]: Started Configure Bluetooth Modems connected by UART.
Apr 14 08:38:11 moode btuart[800]: bcm43xx_init
Apr 14 08:38:11 moode btuart[800]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd
Apr 14 08:38:11 moode btuart[800]: Set Controller UART speed to 3000000 bit/s
Apr 14 08:38:11 moode btuart[800]: Device setup complete
Apr 14 08:38:11 moode systemd[1]: Starting Load/Save RF Kill Switch Status...
Apr 14 08:38:11 moode systemd[1]: Started Load/Save RF Kill Switch Status.
Apr 14 08:38:11 moode systemd[1]: Reached target Bluetooth.
Apr 14 08:38:11 moode systemd[1]: Created slice system-bthelper.slice.
Apr 14 08:38:11 moode systemd[1]: Starting Bluetooth service...
Apr 14 08:38:11 moode bluetoothd[824]: Bluetooth daemon 5.50
Apr 14 08:38:11 moode systemd[1]: Started Bluetooth service.
Apr 14 08:38:11 moode bluetoothd[824]: Starting SDP server
Apr 14 08:38:11 moode systemd[1]: Starting Raspberry Pi bluetooth helper...
Apr 14 08:38:11 moode dbus-daemon[341]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.10' (uid=0 pid=824 comm="/usr/sbin/bluetoothd --noplugin=sap ")
Apr 14 08:38:11 moode bluetoothd[824]: Bluetooth management interface 1.14 initialized
Apr 14 08:38:11 moode kernel: [ 30.843726] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Apr 14 08:38:11 moode kernel: [ 30.843732] Bluetooth: BNEP filters: protocol multicast
Apr 14 08:38:11 moode kernel: [ 30.843745] Bluetooth: BNEP socket layer initialized
Apr 14 08:38:11 moode systemd[1]: Starting Hostname Service...
Apr 14 08:38:11 moode systemd[1]: Started BluezAlsa proxy.
Apr 14 08:38:11 moode bluetoothd[824]: Endpoint registered: sender=:1.11 path=/org/bluez/hci0/A2DP/SBC/Source/1
Apr 14 08:38:11 moode bluetoothd[824]: Endpoint registered: sender=:1.11 path=/org/bluez/hci0/A2DP/SBC/Source/2
Apr 14 08:38:11 moode bluetoothd[824]: Endpoint registered: sender=:1.11 path=/org/bluez/hci0/A2DP/SBC/Sink/1
Apr 14 08:38:11 moode bluetoothd[824]: Endpoint registered: sender=:1.11 path=/org/bluez/hci0/A2DP/SBC/Sink/2
Apr 14 08:38:12 moode dbus-daemon[341]: [system] Successfully activated service 'org.freedesktop.hostname1'
Apr 14 08:38:12 moode systemd[1]: Started Hostname Service.
Apr 14 08:38:12 moode kernel: [ 31.273310] Under-voltage detected! (0x00050005)
Apr 14 08:38:13 moode systemd[1]: Started Raspberry Pi bluetooth helper.
Apr 14 08:38:13 moode bthelper[861]: Raspberry Pi BDADDR already set
Apr 14 08:38:13 moode bthelper[861]: Changing power off succeeded
Apr 14 08:38:13 moode bthelper[861]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:44:A8:81 Powered: no
Apr 14 08:38:13 moode bthelper[861]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:44:A8:81 Discovering: no
Apr 14 08:38:13 moode bthelper[861]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:44:A8:81 Class: 0x00000000
Apr 14 08:38:14 moode kernel: [ 33.095635] debugfs: File 'le_min_key_size' in directory 'hci0' already present!
Apr 14 08:38:14 moode kernel: [ 33.095656] debugfs: File 'le_max_key_size' in directory 'hci0' already present!
Apr 14 08:38:14 moode bthelper[861]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:44:A8:81 Class: 0x000c041c
Apr 14 08:38:14 moode bthelper[861]: Changing power on succeeded
Apr 14 08:38:14 moode systemd[1]: bthelper@hci0.service: Succeeded.
Apr 14 08:38:15 moode kernel: [ 34.313036] FS-Cache: Netfs 'cifs' registered for caching
Apr 14 08:38:15 moode kernel: [ 34.332654] Key type cifs.spnego registered
Apr 14 08:38:15 moode kernel: [ 34.332685] Key type cifs.idmap registered
Apr 14 08:38:15 moode kernel: [ 34.334384] CIFS: Attempting to mount //DISKSTATION/music
Apr 14 08:38:16 moode systemd[1]: systemd-rfkill.service: Succeeded.
Apr 14 08:38:16 moode systemd[1]: systemd-fsckd.service: Succeeded.
Apr 14 08:46:02 moode systemd-timesyncd[297]: Synchronized to time server for the first time 5.103.128.88:123 (2.debian.pool.ntp.org).
Apr 14 08:46:03 moode kernel: [ 37.513258] Voltage normalised (0x00000000)
Apr 14 08:46:19 moode nmbd[479]: [2021/04/14 08:46:19.304946, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Apr 14 08:46:19 moode nmbd[479]: query_name_response: Multiple (2) responses received for a query on subnet 10.0.0.50 for name WORKGROUP<1d>.
Apr 14 08:46:19 moode nmbd[479]: This response was from IP 10.0.0.200, reporting an IP address of 10.0.0.200.
Apr 14 08:46:27 moode systemd[1]: systemd-hostnamed.service: Succeeded.
Apr 14 08:46:39 moode systemd[1]: Created slice User Slice of UID 1000.
Apr 14 08:46:39 moode systemd[1]: Starting User Runtime Directory /run/user/1000...
Apr 14 08:46:39 moode systemd[1]: Started User Runtime Directory /run/user/1000.
Apr 14 08:46:39 moode systemd[1]: Starting User Manager for UID 1000...
Apr 14 08:46:39 moode systemd[1036]: Starting D-Bus User Message Bus Socket.
Apr 14 08:46:39 moode systemd[1036]: Listening on GnuPG cryptographic agent and passphrase cache.
Apr 14 08:46:39 moode systemd[1036]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Apr 14 08:46:39 moode systemd[1036]: Reached target Timers.
Apr 14 08:46:39 moode systemd[1036]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Apr 14 08:46:39 moode systemd[1036]: Reached target Paths.
Apr 14 08:46:39 moode systemd[1036]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Apr 14 08:46:39 moode systemd[1036]: Listening on GnuPG network certificate management daemon.
Apr 14 08:46:39 moode systemd[1036]: Listening on D-Bus User Message Bus Socket.
Apr 14 08:46:39 moode systemd[1036]: Reached target Sockets.
Apr 14 08:46:39 moode systemd[1036]: Reached target Basic System.
Apr 14 08:46:39 moode systemd[1036]: Reached target Default.
Apr 14 08:46:39 moode systemd[1036]: Startup finished in 167ms.
Apr 14 08:46:39 moode systemd[1]: Started User Manager for UID 1000.
Apr 14 08:46:39 moode systemd[1]: Started Session 1 of user pi.And it seems, my I'm getting some exception in my python code (ampcontroller.py) line 196. :
Code:
if Client.status()['state'] == "play":This is related to the python-mpd2 package, but I cant figure out what the problem might be in reading the status, since the code seems to follow the documentation for the package, and I do not know if this could have any negative effects i regards to having enabled bluetooth. The issue seems to be a connection issue.
Code:
rc.local[481]: mpd.base.ConnectionError: Connection lost while reading lineI have tried shutting moode down from both Firefox, and Edge and Chromium. Same result. If I have not played anything over Bluetooth, Shutdown occurs. If I have played something over bluetooth, Nothing happens, when I press shutdown, regardless of the browser.
Because of the error with the code, I'm inclined to think, that this could have some relation to the Bluetooth issue, but I'm not sure.
Has anything changed with moode and mpd2 that might cause this issue?
RE: Bootup/shutdown issues, how to debug - Max Schmeling - 04-15-2021
So I had a bit of progress, using the most overused suggestion ever.
I reinstalled moode vanilla, without any modifications, and it works without errors, it seems. So the error must be in my code , eventhough it has also worked perfectly before I enabled bluetooth, so there must be something in my code that does not play well with the bluetooth part of moode or with the package python-mpd2.
As far as I can see, I get this error from the log:
Code:
Apr 14 08:34:14 moode systemd[1]: Stopped Music Player Daemon.
Apr 14 08:34:14 moode systemd[1]: Started Music Player Daemon.
Apr 14 08:34:14 moode rc.local[481]: Traceback (most recent call last):
Apr 14 08:34:14 moode rc.local[481]: File "/home/pi/ampcontroller.py", line 196, in <module>
Apr 14 08:34:14 moode rc.local[481]: if Client.status()['state'] == "play": # Playing or Airplay active
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 469, in mpd_command
Apr 14 08:34:14 moode rc.local[481]: return wrapper(self, name, args, callback)
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 532, in _execute
Apr 14 08:34:14 moode rc.local[481]: return retval()
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 454, in command_callback
Apr 14 08:34:14 moode rc.local[481]: res = function(self, self._read_lines())
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 394, in _parse_object
Apr 14 08:34:14 moode rc.local[481]: objs = list(self._parse_objects(lines))
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 240, in _parse_objects
Apr 14 08:34:14 moode rc.local[481]: for key, value in self._parse_pairs(lines):
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 235, in _parse_pairs
Apr 14 08:34:14 moode rc.local[481]: for line in lines:
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 586, in _read_lines
Apr 14 08:34:14 moode rc.local[481]: line = self._read_line()
Apr 14 08:34:14 moode rc.local[481]: File "/usr/local/lib/python3.7/dist-packages/mpd/base.py", line 571, in _read_line
Apr 14 08:34:14 moode rc.local[481]: raise ConnectionError("Connection lost while reading line")
Apr 14 08:34:14 moode rc.local[481]: mpd.base.ConnectionError: Connection lost while reading line
Apr 14 08:34:14 moode systemd[1]: rc-local.service: Control process exited, code=exited, status=1/FAILURE
Apr 14 08:34:14 moode systemd[1]: Created slice system-bluealsa\x2daplay.slice.
Apr 14 08:34:14 moode systemd[1]: Started BlueAlsa-Aplay.
Apr 14 08:34:14 moode systemd[1]: rc-local.service: Failed with result 'exit-code'.
Apr 14 08:34:14 moode systemd[1]: Failed to start /etc/rc.local Compatibility.Which refers to this line in my code:
Code:
if Client.status()['state'] == "play":The Client object is an mpd.MPDClient object defined like this:
Code:
Client = mpd.MPDClient() # create client object
Client.timeout = None
Client.idletimeout = None
while True:
try:
Client.connect("localhost", 6600) # connect to localhost:6600
except:
continue
breakI have absolutely no idea why the Client.status code creates this error. It has worked before. Does anybody know how to fix this, or basically how to use python to read if mpd is playing somthing?
The complete Python code is below
Code:
# Import the libraries to use time delays, send os commands and access GPIO pins
import RPi.GPIO as GPIO
import time
import os
import mpd
import sys
import sqlite3 as SQLite3
# Setup Variables
PowerButtonPin = 7
KeepPoweredPin = 8 # Pin to pull high to keep the Pi Supply giving power
RedLedPin = 13 # Set pin number for "OFF" LED
RedExtLedPin = 16 # Set pin number for "OFF" LED
GreenLedPin = 15 # Set pin number for "ON" LED
GreenExtLedPin = 18 # Set pin number for "ON" LED
MainRelayPin = 11 # Set pin number for relay output
Debug = False # Set to true if you want debug from the program. Remember to set it to false if you start the script from rc.local, otherwise your promt will be junked
AmpState = "on" # Stores on/off/standby state of the player and amp
ButtonOverride = False # False except when button initiates standby.
ShutdownActive = False # True when system is shutting down.
TimeSinceActive = time.time() # Stores the time when MoOde was last active
StandbyTimeLimit = 60
OffTimeLimit = 120
# Setup GPIO pins
GPIO.setmode(GPIO.BOARD) # Set pin numbering to board numbering
GPIO.setup(MainRelayPin, GPIO.OUT, initial=GPIO.LOW) # Setup MainRelayPin as an output
#GPIO.setup(PowerButtonPin, GPIO.IN, pull_up_down = GPIO.PUD_DOWN) # Setup PowerButtonPin as an input
GPIO.setup(PowerButtonPin, GPIO.IN) # Setup PowerButtonPin as an input
GPIO.setup(RedLedPin, GPIO.OUT) # Setup RedLedPin as an output
GPIO.setup(GreenLedPin, GPIO.OUT) # Setup GreenLedPin as an output
GPIO.setup(RedExtLedPin, GPIO.OUT) # Setup RedLedPin as an output
GPIO.setup(GreenExtLedPin, GPIO.OUT) # Setup GreenLedPin as an output
GPIO.setup(KeepPoweredPin, GPIO.OUT, initial=GPIO.HIGH) #Setup KeepPoweredPin to pull high to keep the Pi Supply giving power
# Amplifier state control procedure
def SetAmpState(state):
global AmpState
GPIO.output(RedLedPin,False)
GPIO.output(RedExtLedPin,False)
GPIO.output(GreenLedPin,False)
GPIO.output(GreenExtLedPin,False)
if state == "on":
GPIO.output(GreenLedPin,True)
GPIO.output(GreenExtLedPin,True)
GPIO.output(MainRelayPin, GPIO.HIGH)
AmpState = "on"
elif state == "off":
GPIO.output(RedLedPin,True)
GPIO.output(RedExtLedPin,True)
GPIO.output(MainRelayPin, GPIO.LOW)
AmpState = "off"
#os.system("shutdown -h 0&")
os.system("sudo shutdown now")
#sys.exit("Amp was turned off")
#sys.exit(0)
elif state == "standby":
GPIO.output(GreenLedPin,True)
GPIO.output(GreenExtLedPin,True)
GPIO.output(RedLedPin,True)
GPIO.output(RedExtLedPin,True)
GPIO.output(MainRelayPin, GPIO.LOW)
Client.pause(1)
AmpState = "standby"
# Mute Moode player
#os.system("/var/www/vol.sh mute")
if (Debug): print("Amplifier state: {0}".format(AmpState))
# Airplay state check
def IsAirplayOn():
global ButtonOverride
AirplayOn = False
try:
cur = con.cursor()
cur.execute('select value from cfg_system where param=\'airplayactv\'')
data = cur.fetchone()[0]
if (Debug): print("SQL = %s" % data)
if data == "1":
AirplayOn = True
except SQLite3.Error as e:
if (Debug): print("Error %s:" % e.args[0])
if ButtonOverride:
AirplayOn = False
if Debug: print("Returning IsAirplayOn = {0}".format(AirplayOn))
return AirplayOn
def Eval_buttonpress(channel):
global ShutdownActive
global ButtonOverride
global TimeSinceActive
# only react when there is no other shutdown process running
if not ShutdownActive:
ShutdownActive = True
pressed = 1
counter = 0
while (pressed == 1):
if (GPIO.input(PowerButtonPin) == True):
# button is still pressed
counter = counter + 1
if (Debug): print(("Counter is now: {0}".format(counter)))
# break if we count beyond 20 (long-press is a shutdown)
if (counter >= 20):
pressed = 0
else:
time.sleep(0.2)
else:
# button has been released
pressed = 0
if (Debug): print(("Button was pressed for: {0} counts.".format(counter)))
# count how long the button was pressed
if (counter < 2):
# short press
pressed = 0
ShutdownActive = False
else:
if (counter < 20):
# medium length press
if (Debug): print("Muting Moode..")
if AmpState == "on":
SetAmpState("standby")
ButtonOverride = True
else:
SetAmpState("on")
ButtonOverride = False
TimeSinceActive = time.time()
pressed = 0
ShutdownActive = False
else:
# long press, initiate system shutdown
if (Debug): print("shutting down..")
SetAmpState("off")
pressed = 0
#ShutdownActive = False
pressed = 0
# Setup MDPClient and connect to MPD on localhost
Client = mpd.MPDClient() # create client object
Client.timeout = None
Client.idletimeout = None
while True:
try:
Client.connect("localhost", 6600) # connect to localhost:6600
except:
continue
break
# Connect to player database, in order to read Airplay status
try:
con = SQLite3.connect('/var/local/www/db/moode-sqlite3.db')
except SQLite3.Error as e:
if Debug: print("Error %s:" % e.args[0])
sys.exit(1)
# Set PowerButtonPin as an interrupt input
GPIO.add_event_detect(PowerButtonPin, GPIO.RISING, callback = Eval_buttonpress)
SetAmpState("on")
#TimeSinceActive = time.time()
#global ButtonOverride
#global TimeSinceActive
#global AmpState
#global ShutdownActive
time.sleep(20)
TimeSinceActive = time.time()
# main loop
while True:
ElapsedTime = time.time() - TimeSinceActive
if (Debug): print(("{0} seconds have passed since last MPD was last playing.".format(ElapsedTime)))
# if Client.status()['state'] == "play" or IsAirplayOn(): # Playing or Airplay active
if Client.status()['state'] == "play": # Playing or Airplay active
ButtonOverride = False
StandbyTimeLimit = 240
OffTimeLimit = 600
TimeSinceActive = time.time()
if not AmpState == "on" and ShutdownActive == False:
SetAmpState("on") # Set GPIO pins to ON state
if (Debug): print("MPD state = play! Entering ON state")
if (Debug): print(("Amp is on = {0}".format(GPIO.input(MainRelayPin))))
else: # Either stopped or paused
if ElapsedTime >= StandbyTimeLimit:
if AmpState == "on":
SetAmpState("standby") # Set GPIO pins to OFF state
if (Debug): print(("MPD has not been playing for {0} seconds! Entering standby!".format(ElapsedTime)))
if (Debug): print(("Amp is on = {0}".format(GPIO.input(MainRelayPin))))
if ElapsedTime > OffTimeLimit:
if AmpState == "standby":
SetAmpState("off") # Set GPIO pins to OFF state
if (Debug): print(("MPD has not been playing for {0} seconds! Shutting down!".format(ElapsedTime)))
if (Debug): print(("Amp is on = {0}".format(GPIO.input(MainRelayPin))))
time.sleep(0.1)
# Close connection to MPD (not used since the main loop never exits)
Client.close() # send the close command
Client.disconnect() # disconnect from the server
# Close connection to database
if con:
con.close()