Thank you for your donation!


Solved: Sound form NAS is breaking up via WiFi connection
#11
(10-09-2018, 12:39 PM)kitamura_design Wrote: Hi Tim, swizzle,

The WiFi country code is "Japan", of course, of course, and of course I tried to change MPD buffer size already, too.
But 4.3 does not work as I expected.

Next, finally, I tried to revert the kernel to 4.14.54-v7+ via ssh just now, however this modified moOde 4.3 didn't work well, the sound breaking up (choppy sound) is still occurring.

I don't think that the course is the Wifi connection issue at this moment, because there is no problem with moOde 4.2 at all.

Anyway I will switch back to 4.2 until this issue is fixed.
if you want any help this issue, pls let me know.

Thanks,
kitamura_design

@kitamura_design

I think it fair to say we don't have a good hypothesis why your NAS-RPi connection is a problem so we're "shooting in the dark" with suggestions which plausibly might reveal your problem given what we know about moOde/raspbian. 

This is similar to an emergency room doctor ordering up tests to eliminate possible causes of puzzling symptoms presented by the patient. We start with the most likely and progress to the more obscure. 

Tim noted your periodic jump in ping response time. Did you do the other tests he suggested?

Quote:If WiFi interference can be ruled out then examining various logs might show something. 

dmesg
cat /var/log/syslog
ifconfig (examine the tx/rx stats)
iwconfig (examine the signal quality/level)


I have run all the r4.x releases on RPi3B with external 2.4GHz WiFi adapter and on RPi3B+ with internal adapter at 5GHz and have experienced no difficulty communicating with my NAS via the SAMBA protocol. I'm trying to figure out how to replicate your situation but so far I haven't succeeded.

Regards,
Kent
Reply
#12
(10-09-2018, 01:24 PM)Tim Curtis Wrote: Very odd. IME 99% of the time, audio glitch over WiFi is caused by something external to moOde software for example WiFi interference, bad network adapter, misconfigured Router or Samba/NFS server, misconfigured moOde network settings, etc.

The WiFi adapter drivers are part of Linux kernel so if you reverted and no change it would suggest problem is somewhere other than driver or kernel. In any case, even the 2018-06-27 Stretch Lite will update to 4.14.70 when apt-update/upgrade is run. I'd suggest updating to latest 4.14.73.

Code:
echo "y" | sudo PRUNE_MODULES=1 rpi-update 9f230923e419d942cf02fe936ea4fd186d3a21fa

sudo rm -rf /lib/modules.bak
sudo rm -rf /boot.bak
sudo apt-get clean

You could try
- examining your Router syslog and wifi log for anything suspicious.
- specifying ver=2.0 or 3.0 in moOde NAS Config, Advanced, Mount flags
Hi,

I tried to update to kernel 4.14.73+ as you recommend, 4.3 doesn't work with glitch.
On the other hand, 4.2 moOde with 4.14.73+ (I made apt-get update/upgrade via ssh) works correctly (nothing choppy).

And NAS connection has been denied with Mount Flags "ver=2.0 or 3.0 ...", only when the "ver=1.0..."

Thanks,
kitamura_design
Reply
#13
(10-09-2018, 01:46 PM)TheOldPresbyope Wrote:
(10-09-2018, 12:39 PM)kitamura_design Wrote: Hi Tim, swizzle,

The WiFi country code is "Japan", of course, of course, and of course I tried to change MPD buffer size already, too.
But 4.3 does not work as I expected.

Next, finally, I tried to revert the kernel to 4.14.54-v7+ via ssh just now, however this modified moOde 4.3 didn't work well, the sound breaking up (choppy sound) is still occurring.

I don't think that the course is the Wifi connection issue at this moment, because there is no problem with moOde 4.2 at all.

Anyway I will switch back to 4.2 until this issue is fixed.
if you want any help this issue, pls let me know.

Thanks,
kitamura_design

@kitamura_design

I think it fair to say we don't have a good hypothesis why your NAS-RPi connection is a problem so we're "shooting in the dark" with suggestions which plausibly might reveal your problem given what we know about moOde/raspbian. 

This is similar to an emergency room doctor ordering up tests to eliminate possible causes of puzzling symptoms presented by the patient. We start with the most likely and progress to the more obscure. 

Tim noted your periodic jump in ping response time. Did you do the other tests he suggested?

Quote:If WiFi interference can be ruled out then examining various logs might show something. 

dmesg
cat /var/log/syslog
ifconfig (examine the tx/rx stats)
iwconfig (examine the signal quality/level)


I have run all the r4.x releases on RPi3B with external 2.4GHz WiFi adapter and on RPi3B+ with internal adapter at 5GHz and have experienced no difficulty communicating with my NAS via the SAMBA protocol. I'm trying to figure out how to replicate your situation but so far I haven't succeeded.

Regards,
Kent

Hi Kent,

Thanks for your comment.
I really think that's very odd, too. 

I've enjoyed from v2.x to v4.2 on the same Wifi network without any problem on playback.
Why only v4.3 doesn't work?

**
p.s. This is what I listening > try attached m4a, thanks.

Code:
pi@moode:~ $ dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.14.73-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1148 SMP Mon Oct 1 16:57:50 BST 2018
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Plus Rev 1.3
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 8 MiB at 0x3ac00000
[    0.000000] On node 0 totalpages: 242688
[    0.000000] free_area_init_node: node 0, pgdat 80c85280, node_mem_map ba39f000
[    0.000000]   Normal zone: 2133 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 242688 pages, LIFO batch:31
[    0.000000] percpu: Embedded 17 pages/cpu @ba348000 s38720 r8192 d22720 u69632
[    0.000000] pcpu-alloc: s38720 r8192 d22720 u69632 alloc=17*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
[    0.000000] Kernel command line: 8250.nr_uarts=0 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  net.ifnames=0 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=4d3ee428-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 940232K/970752K available (7168K kernel code, 576K rwdata, 2076K rodata, 1024K init, 698K bss, 22328K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                  vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                  fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                  vmalloc : 0xbb800000 - 0xff800000   (1088 MB)
                  lowmem  : 0x80000000 - 0xbb400000   ( 948 MB)
                  modules : 0x7f000000 - 0x80000000   (  16 MB)
                    .text : 0x80008000 - 0x80800000   (8160 kB)
                    .init : 0x80b00000 - 0x80c00000   (1024 kB)
                    .data : 0x80c00000 - 0x80c9017c   ( 577 kB)
                     .bss : 0x80c97f10 - 0x80d468b0   ( 699 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 25274 entries in 75 pages
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000022] Switching to timer-based delay loop, resolution 52ns
[    0.000271] Console: colour dummy device 80x30
[    0.000812] console [tty1] enabled
[    0.000849] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.000889] pid_max: default: 32768 minimum: 301
[    0.001217] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001250] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002204] Disabling memory control group subsystem
[    0.002298] CPU: Testing write buffer coherency: ok
[    0.002725] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.003144] Setting up static identity map for 0x100000 - 0x10003c
[    0.003284] Hierarchical SRCU implementation.
[    0.003978] smp: Bringing up secondary CPUs ...
[    0.004777] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.005623] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.006451] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.006555] smp: Brought up 1 node, 4 CPUs
[    0.006629] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.006651] CPU: All CPU(s) started in HYP mode.
[    0.006669] CPU: Virtualization extensions available.
[    0.007567] devtmpfs: initialized
[    0.017677] random: get_random_u32 called from bucket_table_alloc+0xfc/0x24c with crng_init=0
[    0.018392] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.018637] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.018681] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.019252] pinctrl core: initialized pinctrl subsystem
[    0.020055] NET: Registered protocol family 16
[    0.022693] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.027495] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.027527] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.027750] Serial: AMBA PL011 UART driver
[    0.029416] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.029883] uart-pl011 3f201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[    0.062043] bcm2835-dma 3f007000.dma: DMA legacy API manager at bb813000, dmachans=0x1
[    0.063480] SCSI subsystem initialized
[    0.063719] usbcore: registered new interface driver usbfs
[    0.063787] usbcore: registered new interface driver hub
[    0.063887] usbcore: registered new device driver usb
[    0.070086] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-09-21 15:43
[    0.071439] clocksource: Switched to clocksource arch_sys_counter
[    0.147941] VFS: Disk quotas dquot_6.6.0
[    0.148053] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.148256] FS-Cache: Loaded
[    0.148469] CacheFiles: Loaded
[    0.157294] NET: Registered protocol family 2
[    0.158031] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.158161] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.158363] TCP: Hash tables configured (established 8192 bind 8192)
[    0.158509] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.158570] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.158810] NET: Registered protocol family 1
[    0.159285] RPC: Registered named UNIX socket transport module.
[    0.159309] RPC: Registered udp transport module.
[    0.159329] RPC: Registered tcp transport module.
[    0.159348] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.160896] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    0.163665] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.171809] FS-Cache: Netfs 'nfs' registered for caching
[    0.172434] NFS: Registering the id_resolver key type
[    0.172487] Key type id_resolver registered
[    0.172507] Key type id_legacy registered
[    0.172535] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.174472] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    0.174631] io scheduler noop registered
[    0.174653] io scheduler deadline registered (default)
[    0.174949] io scheduler cfq registered
[    0.174971] io scheduler mq-deadline registered
[    0.174992] io scheduler kyber registered
[    0.177296] BCM2708FB: allocated DMA memory fad00000
[    0.177339] BCM2708FB: allocated DMA channel 0 @ bb813000
[    0.185917] Console: switching to colour frame buffer device 82x26
[    0.194224] bcm2835-rng 3f104000.rng: hwrng registered
[    0.196655] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    0.201816] vc-sm: Videocore shared memory driver
[    0.204406] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    0.218549] brd: module loaded
[    0.229458] loop: module loaded
[    0.231811] Loading iSCSI transport class v2.0-870.
[    0.234786] libphy: Fixed MDIO Bus: probed
[    0.237156] usbcore: registered new interface driver lan78xx
[    0.239482] usbcore: registered new interface driver smsc95xx
[    0.241668] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.269303] dwc_otg 3f980000.usb: base=0xf0980000
[    0.471705] Core Release: 2.80a
[    0.473883] Setting default values for core params
[    0.476148] Finished setting default values for core params
[    0.678702] Using Buffer DMA mode
[    0.680978] Periodic Transfer Interrupt Enhancement - disabled
[    0.683388] Multiprocessor Interrupt Enhancement - disabled
[    0.685770] OTG VER PARAM: 0, OTG VER FLAG: 0
[    0.688107] Dedicated Tx FIFOs mode
[    0.690742] WARN::dwc_otg_hcd_init:1046: FIQ DMA bounce buffers: virt = 0xbad14000 dma = 0xfad14000 len=9024
[    0.695347] FIQ FSM acceleration enabled for :
              Non-periodic Split Transactions
              Periodic Split Transactions
              High-Speed Isochronous Endpoints
              Interrupt/Control Split Transaction hack enabled
[    0.706266] dwc_otg: Microframe scheduler enabled
[    0.706316] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x805e9fe4
[    0.708575] WARN::hcd_init_fiq:460: FIQ ASM at 0x805ea34c length 36
[    0.710807] WARN::hcd_init_fiq:486: MPHI regs_base at 0xf0006000
[    0.713146] dwc_otg 3f980000.usb: DWC OTG Controller
[    0.715432] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    0.717774] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[    0.720099] Init: Port Power? op_state=1
[    0.722378] Init: Power Port (0)
[    0.724761] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    0.727076] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.729378] usb usb1: Product: DWC OTG Controller
[    0.731656] usb usb1: Manufacturer: Linux 4.14.73-v7+ dwc_otg_hcd
[    0.733939] usb usb1: SerialNumber: 3f980000.usb
[    0.736782] hub 1-0:1.0: USB hub found
[    0.738993] hub 1-0:1.0: 1 port detected
[    0.741570] dwc_otg: FIQ enabled
[    0.741576] dwc_otg: NAK holdoff enabled
[    0.741581] dwc_otg: FIQ split-transaction FSM enabled
[    0.741591] Module dwc_common_port init
[    0.741808] usbcore: registered new interface driver usb-storage
[    0.744100] mousedev: PS/2 mouse device common for all mice
[    0.746326] IR NEC protocol handler initialized
[    0.748500] IR RC5(x/sz) protocol handler initialized
[    0.750705] IR RC6 protocol handler initialized
[    0.752914] IR JVC protocol handler initialized
[    0.754998] IR Sony protocol handler initialized
[    0.757088] IR SANYO protocol handler initialized
[    0.759176] IR Sharp protocol handler initialized
[    0.761167] IR MCE Keyboard/mouse protocol handler initialized
[    0.763210] IR XMP protocol handler initialized
[    0.765883] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[    0.768228] bcm2835-cpufreq: min=600000 max=1400000
[    0.770675] sdhci: Secure Digital Host Controller Interface driver
[    0.772835] sdhci: Copyright(c) Pierre Ossman
[    0.775274] mmc-bcm2835 3f300000.mmc: could not get clk, deferring probe
[    0.777745] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    0.780036] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.783666] ledtrig-cpu: registered to indicate activity on CPUs
[    0.786058] hidraw: raw HID events driver (C) Jiri Kosina
[    0.788527] usbcore: registered new interface driver usbhid
[    0.790828] usbhid: USB HID core driver
[    0.793672] vchiq: vchiq_init_state: slot_zero = bad80000, is_master = 0
[    0.797402] [vc_sm_connected_init]: start
[    0.806207] [vc_sm_connected_init]: end - returning 0
[    0.809105] Initializing XFRM netlink socket
[    0.811514] NET: Registered protocol family 17
[    0.813969] Key type dns_resolver registered
[    0.816777] Registering SWP/SWPB emulation handler
[    0.819766] registered taskstats version 1
[    0.828090] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    0.830655] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[    0.837342] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    0.839872] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[    0.902054] sdhost: log_buf @ bad13000 (fad13000)
[    0.940896] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    0.944885] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.948727] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.951571] Indeed it is in host mode hprt0 = 00021501
[    1.016005] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.030169] random: fast init done
[    1.041466] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    1.044681] of_cfs_init
[    1.046875] of_cfs_init: OK
[    1.049419] Waiting for root device PARTUUID=4d3ee428-02...
[    1.105543] mmc1: new high speed SDIO card at address 0001
[    1.161550] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.163899] Indeed it is in host mode hprt0 = 00001101
[    1.421745] usb 1-1: New USB device found, idVendor=0424, idProduct=2514
[    1.424095] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.426926] hub 1-1:1.0: USB hub found
[    1.429229] hub 1-1:1.0: 4 ports detected
[    1.751465] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    1.881697] usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514
[    1.883916] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.886588] hub 1-1.1:1.0: USB hub found
[    1.888811] hub 1-1.1:1.0: 3 ports detected
[    2.211463] usb 1-1.1.2: new high-speed USB device number 4 using dwc_otg
[    2.342323] usb 1-1.1.2: New USB device found, idVendor=0781, idProduct=5571
[    2.344701] usb 1-1.1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    2.349271] usb 1-1.1.2: Product: Cruzer Fit
[    2.351612] usb 1-1.1.2: Manufacturer: SanDisk
[    2.353894] usb 1-1.1.2: SerialNumber: 4C530001171117119115
[    2.356867] usb-storage 1-1.1.2:1.0: USB Mass Storage device detected
[    2.359764] scsi host0: usb-storage 1-1.1.2:1.0
[    2.661464] usb 1-1.1.1: new high-speed USB device number 5 using dwc_otg
[    2.791821] usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800
[    2.794253] usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.066859] libphy: lan78xx-mdiobus: probed
[    3.433430] scsi 0:0:0:0: Direct-Access     SanDisk  Cruzer Fit       1.00 PQ: 0 ANSI: 6
[    3.439073] sd 0:0:0:0: [sda] 61341696 512-byte logical blocks: (31.4 GB/29.3 GiB)
[    3.445220] sd 0:0:0:0: [sda] Write Protect is off
[    3.447778] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00
[    3.448138] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    3.461028]  sda: sda1 sda2
[    3.465463] sd 0:0:0:0: [sda] Attached SCSI removable disk
[    3.497236] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
[    3.502477] VFS: Mounted root (ext4 filesystem) readonly on device 8:2.
[    3.516751] devtmpfs: mounted
[    3.522473] Freeing unused kernel memory: 1024K
[    4.124617] systemd[1]: System time before build time, advancing clock.
[    4.277215] NET: Registered protocol family 10
[    4.281206] Segment Routing with IPv6
[    4.296342] ip_tables: (C) 2000-2006 Netfilter Core Team
[    4.323036] random: systemd: uninitialized urandom read (16 bytes read)
[    4.331545] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[    4.340619] systemd[1]: Detected architecture arm.
[    4.354491] systemd[1]: Set hostname to <moode>.
[    4.402108] random: systemd: uninitialized urandom read (16 bytes read)
[    4.426003] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read)
[    5.119244] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    5.126372] systemd[1]: Created slice User and Session Slice.
[    5.132329] systemd[1]: Reached target Swap.
[    5.138339] systemd[1]: Listening on Syslog Socket.
[    5.174025] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    5.183267] systemd[1]: Listening on Journal Socket (/dev/log).
[    5.189546] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    5.685311] random: crng init done
[    5.685327] random: 7 urandom warning(s) missed due to ratelimiting
[    5.791738] EXT4-fs (sda2): re-mounted. Opts: (null)
[    5.879911] systemd-journald[90]: Received request to flush runtime journal from PID 1
[    6.460181] snd-rpi-iqaudio-dac soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered - will retry
[    6.471213] snd-rpi-iqaudio-dac soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered - will retry
[    6.827474] snd-rpi-iqaudio-dac soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered - will retry
[    6.830660] brcmfmac: F1 signature read @0x18000000=0x15264345
[    6.841795] brcmfmac: brcmf_fw_map_chip_to_name: using brcm/brcmfmac43455-sdio.bin for chip 0x004345(17221) rev 0x000006
[    6.842479] snd-rpi-iqaudio-dac soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered - will retry
[    6.842692] usbcore: registered new interface driver brcmfmac
[    6.911702] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    6.999262] snd-rpi-iqaudio-dac soc:sound: pcm512x-hifi <-> 3f203000.i2s mapping ok
[    7.237298] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Feb 27 2018 03:15:32 version 7.45.154 (r684107 CY) FWID 01-4fbe0b04
[    7.237854] brcmfmac: brcmf_c_preinit_dcmds: CLM version = API: 12.2 Data: 9.10.105 Compiler: 1.29.4 ClmImport: 1.36.3 Creation: 2018-03-09 18:56:28
[    8.943533] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[    8.943563] brcmfmac: power management disabled
[    9.215796] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   11.906084] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   56.175258] uart-pl011 3f201000.serial: no DMA platform data
[   62.665168] Bluetooth: Core ver 2.22
[   62.665249] NET: Registered protocol family 31
[   62.665253] Bluetooth: HCI device and connection manager initialized
[   62.666141] Bluetooth: HCI socket layer initialized
[   62.666156] Bluetooth: L2CAP socket layer initialized
[   62.666201] Bluetooth: SCO socket layer initialized
[   62.678328] Bluetooth: HCI UART driver ver 2.3
[   62.678337] Bluetooth: HCI UART protocol H4 registered
[   62.678341] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   62.678459] Bluetooth: HCI UART protocol Broadcom registered
[   62.821670] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   62.821680] Bluetooth: BNEP filters: protocol multicast
[   62.821696] Bluetooth: BNEP socket layer initialized
[   63.335455] FS-Cache: Netfs 'cifs' registered for caching
[   63.335712] Key type cifs.spnego registered
[   63.335721] Key type cifs.idmap registered
[  115.942200] pcm512x 1-004c: No SCLK, using BCLK: -2
[  148.882972] pcm512x 1-004c: No SCLK, using BCLK: -2
[  477.658969] CIFS VFS: cifs_mount failed w/return code = -112
[  493.234222] CIFS VFS: cifs_mount failed w/return code = -112
[ 1214.411495] pcm512x 1-004c: No SCLK, using BCLK: -2

Code:
pi@moode:~ $ ifconfig
eth0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
       ether b8:27:eb:2a:09:02  txqueuelen 1000  (Ethernet)
       RX packets 0  bytes 0 (0.0 B)
       RX errors 0  dropped 0  overruns 0  frame 0
       TX packets 0  bytes 0 (0.0 B)
       TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
       inet 127.0.0.1  netmask 255.0.0.0
       inet6 ::1  prefixlen 128  scopeid 0x10<host>
       loop  txqueuelen 1000  (Local Loopback)
       RX packets 2574  bytes 844352 (824.5 KiB)
       RX errors 0  dropped 0  overruns 0  frame 0
       TX packets 2574  bytes 844352 (824.5 KiB)
       TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
       inet 10.0.1.8  netmask 255.255.255.0  broadcast 10.0.1.255
       inet6 fe80::e4fa:f88d:a0e1:d1c4  prefixlen 64  scopeid 0x20<link>
       ether b8:27:eb:7f:5c:57  txqueuelen 1000  (Ethernet)
       RX packets 247166  bytes 302539761 (288.5 MiB)
       RX errors 0  dropped 24  overruns 0  frame 0
       TX packets 150656  bytes 21596771 (20.5 MiB)
       TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

Code:
pi@moode:~ $ iwconfig
eth0      no wireless extensions.

lo        no wireless extensions.

wlan0     IEEE 802.11  ESSID:"Kitamura_LAN 5GHz"  
         Mode:Managed  Frequency:5.6 GHz  Access Point: 60:33:4B:E0:58:0E  
         Bit Rate=150 Mb/s   Tx-Power=31 dBm  
         Retry short limit:7   RTS thr:off   Fragment thr:off
         Power Management:on
         Link Quality=47/70  Signal level=-63 dBm  
         Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
         Tx excessive retries:0  Invalid misc:0   Missed beacon:0
Reply
#14
Looks ok. Are there any errors in MPD log when you play a song file from your NAS?

cat /var/log/mpd/log
Reply
#15
The ifconfig and iwconfig output looks reasonable. [1]

The only thing odd I see is at the end of your dmesg output

Code:
[  477.658969] CIFS VFS: cifs_mount failed w/return code = -112
[  493.234222] CIFS VFS: cifs_mount failed w/return code = -112


This says your moOde player twice tried to mount a CIFS (e.g., SAMBA) filesystem and failed. That 112 return code breaks down to 64 ("some mount succeeded") + 32 ("mount failure") + 16 ("problems writing or locking /etc/mtab"). I think the essential point here is the "mount failure".

Did it mount later? Was this your NAS? What does the mount command say?

As an example, I have no such message in my dmesg output on a working r4.3 system and I have the following excerpt from running the mount command which shows my NAS (OMV-HC1) is mounted as a CIFS filesystem (with 'XXX' substituted for the actual username)

Code:
pi@moode:~ $ mount

//OMV-HC1/Music on /mnt/NAS/OMV-HC1 type cifs (ro,relatime,vers=1.0,cache=strict,username=XXXX,domain=,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.1.12,soft,unix,posixpaths,serverino,mapposix,acl,rsize=61440,wsize=65536,echo_interval=60,actimeo=1)


Still looking for an aha moment.

Regards,
Kent

[1] if you were using an external WiFi adapter, I'd point to the "Power Management:on" line output by iwconfig, but raspbian disables power management for the internal adapter (you can find it in your dmesg outout) and apparently iwconfig lies about it (consult the RPi forums if you're interested).
Reply
#16
(10-09-2018, 04:33 PM)Tim Curtis Wrote: Looks ok. Are there any errors in MPD log when you play a song file from your NAS?

cat /var/log/mpd/log

Hi Tim,

I found some errors in MPD Log as below;

Code:
pi@moode:~ $ cat /var/log/mpd/log
Oct 09 18:48 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:49 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:49 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:49 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:49 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:49 : player: played "NAS/kitamura-music/Idles/Joy as an Act of Resistance/10 Idles -  Gram Rock .aif"
Oct 09 18:51 : exception: Failed to decode /var/lib/mpd/music/NAS/kitamura-music/Idles/Joy as an Act of Resistance/10 Idles -  Gram Rock .aif
Oct 09 18:51 : exception: nested: Failed to open /var/lib/mpd/music/NAS/kitamura-music/Idles/Joy as an Act of Resistance/10 Idles -  Gram Rock .aif: No such file or directory
Oct 09 18:51 : player: played "NAS/kitamura-music/Idles/Joy as an Act of Resistance/10 Idles -  Gram Rock .aif"
Oct 09 18:55 : player: played "NAS/kitamura-music/Idles/Joy as an Act of Resistance/10 Idles -  Gram Rock .aif"
Oct 09 18:56 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:56 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 18:56 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:04 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:04 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:04 : player: played "NAS/kitamura-music/Bill Evans/Some Other Time; The Lost Session From the Black Forest-DISC1/02 Bill Evans - Very Early.aif"
Oct 09 19:27 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:27 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:27 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:27 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:27 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:27 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:28 : player: played "NAS/kitamura-music/Bill Evans/Some Other Time; The Lost Session From the Black Forest-DISC1/01 Bill Evans - You Go to My Head.aif"
Oct 09 19:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 19:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 20:55 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 20:55 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 20:55 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 20:55 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 20:58 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 20:58 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:03 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:03 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:03 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:03 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:03 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:03 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:04 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:04 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:07 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:07 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:07 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:07 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:07 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:07 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:09 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:09 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:09 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 21:09 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:23 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:29 : player: played "NAS/kitamura-music/CARPENTERS/シングルズ 1969-1981/シングルズ 1969-1981_21_星空に愛を(コーリング・オキュパンツ).wav"
Oct 09 23:30 : exception: Failed to decode /var/lib/mpd/music/NAS/kitamura-music/CARPENTERS/シングルズ 1969-1981/シングルズ 1969-1981_21_星空に愛を(コーリング・オキュパンツ).wav
Oct 09 23:30 : exception: nested: Failed to open /var/lib/mpd/music/NAS/kitamura-music/CARPENTERS/シングルズ 1969-1981/シングルズ 1969-1981_21_星空に愛を(コーリング・オキュパンツ).wav: No such file or directory
Oct 09 23:30 : player: played "NAS/kitamura-music/CARPENTERS/シングルズ 1969-1981/シングルズ 1969-1981_21_星空に愛を(コーリング・オキュパンツ).wav"
Oct 09 23:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:31 : player: played "NAS/kitamura-music/CARPENTERS/シングルズ 1969-1981/シングルズ 1969-1981_21_星空に愛を(コーリング・オキュパンツ).wav"
Oct 09 23:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:32 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:32 : player: Decoder is too slow; playing silence to avoid xrun
Oct 09 23:32 : player: Decoder is too slow; playing silence to avoid xrun

Oct 09 23:50 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:04 : player: played "NAS/kitamura-music/CARPENTERS/シングルズ 1969-1981/シングルズ 1969-1981_21_星空に愛を(コーリング・オキュパンツ).wav"
Oct 10 01:10 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:10 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:10 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:10 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:10 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:11 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:11 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:11 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:11 : player: played "NAS/kitamura-music/Bill Evans/Some Other Time; The Lost Session From the Black Forest-DISC1/01 Bill Evans - You Go to My Head.aif"
Oct 10 01:12 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 01:13 : player: Decoder is too slow; playing silence to avoid xrun

kitamura_design
Reply
#17
(10-09-2018, 04:40 PM)TheOldPresbyope Wrote: The ifconfig and iwconfig output looks reasonable. [1]

The only thing odd I see is at the end of your dmesg output

Code:
[  477.658969] CIFS VFS: cifs_mount failed w/return code = -112
[  493.234222] CIFS VFS: cifs_mount failed w/return code = -112


This says your moOde player twice tried to mount a CIFS (e.g., SAMBA) filesystem and failed. That 112 return code breaks down to 64 ("some mount succeeded") + 32 ("mount failure") + 16 ("problems writing or locking /etc/mtab"). I think the essential point here is the "mount failure".

Did it mount later? Was this your NAS? What does the mount command say?

As an example, I have no such message in my dmesg output on a working r4.3 system and I have the following excerpt from running the mount command which shows my NAS (OMV-HC1) is mounted as a CIFS filesystem (with 'XXX' substituted for the actual username)

Code:
pi@moode:~ $ mount

//OMV-HC1/Music on /mnt/NAS/OMV-HC1 type cifs (ro,relatime,vers=1.0,cache=strict,username=XXXX,domain=,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.1.12,soft,unix,posixpaths,serverino,mapposix,acl,rsize=61440,wsize=65536,echo_interval=60,actimeo=1)


Still looking for an aha moment.

Regards,
Kent

[1] if you were using an external WiFi adapter, I'd point to the "Power Management:on" line output by iwconfig, but raspbian disables power management for the internal adapter (you can find it in your dmesg outout) and apparently iwconfig lies about it (consult the RPi forums if you're interested).

Hi,

The CIFS error could be occurred when I tried to mount with some "Mount flags" at ver=2.0 and 3.0 as following with Tim's advice -- Both trial were failed.
I cannot understand what you're saying -- This NAS is mine, of course.

kitamura_design
Reply
#18
This error in mpd log suggests a possible codec issue.
Oct 09 18:48 : player: Decoder is too slow; playing silence to avoid xrun

MPD in moOde 4.2 used only ffmpeg. moOde 4.3 added the libaudiofile codec library.

Lets try turning on verbose logging in MPD and see what codec its using for the aif and wav files.

1. sudo nano /etc/mpd.conf
2. change
log_level "default"
to
log_level "verbose"
3. save the file
4. sudo systemctl restart mpd
5. play a song
6. post the verbose log output for that particular song play. It should list the codec, either [audiofile] or [ffmpeg].

-Tim
Reply
#19
(10-09-2018, 05:14 PM)Tim Curtis Wrote: This error in mpd log suggests a possible codec issue.
Oct 09 18:48 : player: Decoder is too slow; playing silence to avoid xrun

MPD in moOde 4.2 used only ffmpeg. moOde 4.3 added the libaudiofile codec library.

Lets try turning on verbose logging in MPD and see what codec its using for the aif and wav files.

1. sudo nano /etc/mpd.conf
2. change
log_level "default"
to
log_level "verbose"
3. save the file
4. sudo systemctl restart mpd
5. play a song
6. post the verbose log output for that particular song play. It should list the codec, either [audiofile] or [ffmpeg].

-Tim

Hi Tim,

Here is the verbose log;
Code:
Oct 10 02:28 : client: [40] opened from 127.0.0.1:46376
Oct 10 02:28 : client: [40] process command "next"
Oct 10 02:28 : playlist: play 11:"NAS/kitamura-music/Bill Evans/Some Other Time; The Lost Session From the Black Forest-DISC1/01 Bill Evans - You Go to My Head.aif"
Oct 10 02:28 : decoder_thread: probing plugin audiofile
Oct 10 02:28 : decoder: audio_format=96000:24:2, seekable=true
Oct 10 02:28 : playlist: queue song 11:"NAS/kitamura-music/Idles/Joy as an Act of Resistance/01 Idles - Colossus .aif"
Oct 10 02:28 : client: [40] command returned 0
Oct 10 02:28 : client: [40] process command "close"
Oct 10 02:28 : client: [40] command returned 3
Oct 10 02:28 : client: [40] closed
Oct 10 02:28 : client: [37] process command "status"
Oct 10 02:28 : client: [37] command returned 0
Oct 10 02:28 : client: [37] process command "currentsong"
Oct 10 02:28 : client: [37] command returned 0
Oct 10 02:28 : client: [37] process command "close"
Oct 10 02:28 : client: [37] command returned 3
Oct 10 02:28 : client: [37] closed
Oct 10 02:28 : client: [41] opened from 127.0.0.1:46380
Oct 10 02:28 : client: [41] process command "close"
Oct 10 02:28 : client: [41] command returned 3
Oct 10 02:28 : client: [41] closed
Oct 10 02:28 : client: [42] opened from 127.0.0.1:46384
Oct 10 02:28 : client: [42] process command "playlistinfo"
Oct 10 02:28 : client: [42] command returned 0
Oct 10 02:28 : client: [42] process command "close"
Oct 10 02:28 : client: [42] command returned 3
Oct 10 02:28 : client: [42] closed
Oct 10 02:28 : client: [43] opened from 127.0.0.1:46388
Oct 10 02:28 : client: [43] process command "status"
Oct 10 02:28 : client: [43] command returned 0
Oct 10 02:28 : client: [43] process command "idle"
Oct 10 02:28 : client: [43] command returned 1
Oct 10 02:28 : client: [44] opened from 127.0.0.1:46392
Oct 10 02:28 : client: [44] process command "close"
Oct 10 02:28 : client: [44] command returned 3
Oct 10 02:28 : client: [44] closed
Oct 10 02:28 : state_file: Saving state file /var/lib/mpd/state
Oct 10 02:28 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:28 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:28 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:29 : client: [45] opened from 127.0.0.1:46398
Oct 10 02:29 : client: [45] process command "next"
Oct 10 02:29 : playlist: play 11:"NAS/kitamura-music/Idles/Joy as an Act of Resistance/01 Idles - Colossus .aif"
Oct 10 02:29 : decoder_thread: probing plugin audiofile
Oct 10 02:29 : decoder: audio_format=96000:24:2, seekable=true
Oct 10 02:29 : playlist: queue song 11:"NAS/kitamura-music/Fabrizio Sotti Trio/Forty/01 Fabrizio Sotti - Redemption.aif"
Oct 10 02:29 : client: [45] command returned 0
Oct 10 02:29 : client: [45] process command "close"
Oct 10 02:29 : client: [45] command returned 3
Oct 10 02:29 : client: [45] closed
Oct 10 02:29 : client: [43] process command "status"
Oct 10 02:29 : client: [43] command returned 0
Oct 10 02:29 : client: [43] process command "currentsong"
Oct 10 02:29 : client: [43] command returned 0
Oct 10 02:29 : client: [43] process command "close"
Oct 10 02:29 : client: [43] command returned 3
Oct 10 02:29 : client: [43] closed
Oct 10 02:29 : client: [46] opened from 127.0.0.1:46402
Oct 10 02:29 : client: [46] process command "close"
Oct 10 02:29 : client: [46] command returned 3
Oct 10 02:29 : client: [46] closed
Oct 10 02:29 : client: [47] opened from 127.0.0.1:46406
Oct 10 02:29 : client: [47] process command "playlistinfo"
Oct 10 02:29 : client: [47] command returned 0
Oct 10 02:29 : client: [47] process command "close"
Oct 10 02:29 : client: [47] command returned 3
Oct 10 02:29 : client: [47] closed
Oct 10 02:29 : client: [48] opened from 127.0.0.1:46410
Oct 10 02:29 : client: [48] process command "status"
Oct 10 02:29 : client: [48] command returned 0
Oct 10 02:29 : client: [48] process command "idle"
Oct 10 02:29 : client: [48] command returned 1
Oct 10 02:29 : client: [49] opened from 127.0.0.1:46414
Oct 10 02:29 : client: [49] process command "close"
Oct 10 02:29 : client: [49] command returned 3
Oct 10 02:29 : client: [49] closed
Oct 10 02:29 : state_file: Saving state file /var/lib/mpd/state
Oct 10 02:30 : client: [50] opened from 127.0.0.1:46420
Oct 10 02:30 : client: [50] process command "currentsong"
Oct 10 02:30 : client: [50] command returned 0
Oct 10 02:30 : client: [50] process command "status"
Oct 10 02:30 : client: [50] command returned 0
Oct 10 02:30 : client: [50] closed
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:30 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : client: [51] opened from 127.0.0.1:46424
Oct 10 02:31 : client: [51] process command "next"
Oct 10 02:31 : playlist: play 11:"NAS/kitamura-music/Fabrizio Sotti Trio/Forty/01 Fabrizio Sotti - Redemption.aif"
Oct 10 02:31 : decoder_thread: probing plugin audiofile
Oct 10 02:31 : decoder: audio_format=96000:24:2, seekable=true
Oct 10 02:31 : client: [51] command returned 0
Oct 10 02:31 : client: [51] process command "close"
Oct 10 02:31 : client: [51] command returned 3
Oct 10 02:31 : client: [51] closed
Oct 10 02:31 : client: [48] process command "status"
Oct 10 02:31 : client: [48] command returned 0
Oct 10 02:31 : client: [48] process command "currentsong"
Oct 10 02:31 : client: [48] command returned 0
Oct 10 02:31 : client: [48] process command "close"
Oct 10 02:31 : client: [48] command returned 3
Oct 10 02:31 : client: [48] closed
Oct 10 02:31 : client: [52] opened from 127.0.0.1:46428
Oct 10 02:31 : client: [52] process command "close"
Oct 10 02:31 : client: [52] command returned 3
Oct 10 02:31 : client: [52] closed
Oct 10 02:31 : client: [53] opened from 127.0.0.1:46432
Oct 10 02:31 : client: [53] process command "playlistinfo"
Oct 10 02:31 : client: [53] command returned 0
Oct 10 02:31 : client: [53] process command "close"
Oct 10 02:31 : client: [53] command returned 3
Oct 10 02:31 : client: [53] closed
Oct 10 02:31 : client: [54] opened from 127.0.0.1:46436
Oct 10 02:31 : client: [54] process command "status"
Oct 10 02:31 : client: [54] command returned 0
Oct 10 02:31 : client: [54] process command "idle"
Oct 10 02:31 : client: [54] command returned 1
Oct 10 02:31 : client: [55] opened from 127.0.0.1:46440
Oct 10 02:31 : client: [55] process command "close"
Oct 10 02:31 : client: [55] command returned 3
Oct 10 02:31 : client: [55] closed
Oct 10 02:31 : state_file: Saving state file /var/lib/mpd/state
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:31 : player: Decoder is too slow; playing silence to avoid xrun
Oct 10 02:32 : client: [56] opened from 127.0.0.1:46446
Oct 10 02:32 : client: [56] process command "pause"
Oct 10 02:32 : output: closed plugin=alsa name="ALSA default"
Oct 10 02:32 : client: [56] command returned 0
Oct 10 02:32 : client: [56] process command "close"
Oct 10 02:32 : client: [56] command returned 3
Oct 10 02:32 : client: [56] closed
Oct 10 02:32 : client: [54] process command "status"
Oct 10 02:32 : client: [54] command returned 0
Oct 10 02:32 : client: [54] process command "currentsong"
Oct 10 02:32 : client: [54] command returned 0
Oct 10 02:32 : client: [54] process command "close"
Oct 10 02:32 : client: [54] command returned 3
Oct 10 02:32 : client: [54] closed
Oct 10 02:32 : client: [57] opened from 127.0.0.1:46450
Oct 10 02:32 : client: [57] process command "close"
Oct 10 02:32 : client: [57] command returned 3
Oct 10 02:32 : client: [57] closed
Oct 10 02:32 : client: [58] opened from 127.0.0.1:46454
Oct 10 02:32 : client: [58] process command "status"
Oct 10 02:32 : client: [58] command returned 0
Oct 10 02:32 : client: [58] process command "idle"
Oct 10 02:32 : client: [58] command returned 1
Oct 10 02:32 : client: [59] opened from 127.0.0.1:46458
Oct 10 02:32 : client: [59] process command "close"
Oct 10 02:32 : client: [59] command returned 3
Oct 10 02:32 : client: [59] closed
Oct 10 02:32 : state_file: Saving state file /var/lib/mpd/state

Thanks,
kitamura_design
Reply
#20
Ok, that confirms that the audiofile codec library is being used and not ffmpeg.

Here is how to revert to moOde 4.2 MPD that only uses only the ffmpeg codec library.

1. cd ~
2. save existing moode 4.3 MPD
cp /usr/local/bin/mpd ./mpd-0.20.20-audiofile
3. download and unzip moOde 4.2 MPD
wget http://moodeaudio.org/test/mpd-0.20.20-ffmpeg.zip
unzip mpd-0.20.20-ffmpeg.zip
4. replace moOde 4.3 MPD with moOde 4.2 MPD
sudo mv mpd-0.20.20-ffmpeg /usr/local/bin/mpd
5. Verify that "[audiofile] wav au aiff aif" is not listed under the "Decoders plugins:" section
mpd -V
6. sudo systemctl restart mpd
7. Play a song file
8. Examine MPD log and verify that ffmpeg codec library is being used
9. Report whether audio glitches occur
Reply


Forum Jump: