joerg-krause writes
I am running upmpdcli 1.2.12, libupnpp 0.15.1, and latest sc2mpd from the git master branch on an embedded Linux device. I build a sc2mpd version linked against latest oh libs, as well as a version linked against the oh libs having the same version than in the ohbuild scripts.
On a Windows host I installed and started latest Songcast tool. On a Linux host I am running upplay. The Songcast tools detects the OH Receiver, as well as upplay detects the OH Sender and OH Receiver.
When I select the OH Sender and try to link it to the OH Receiver, the upmpdcli log file outputs:
:4:src/ohreceiver.cxx:303::OHReceiver::sender
:4:libupnpp/device/device.cxx:382::UPNP_EVENT_SUBSCRIPTION_REQUEST: urn:av-openhome-org:serviceId:Receiver
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: TransportState. Params: <?xml version="1.0"? >
<u:TransportState xmlns:u="urn:av-openhome-org:service:Receiver:1" ></u:TransportState >
:4:src/ohreceiver.cxx:311::OHReceiver::transportState
:4:src/ohreceiver.cxx:318::OHReceiver::transportState: Stopped
:4:libupnpp/device/device.cxx:382::UPNP_EVENT_SUBSCRIPTION_REQUEST: urn:av-openhome-org:serviceId:Product
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: SourceIndex. Params: <?xml version="1.0"? >
<u:SourceIndex xmlns:u="urn:av-openhome-org:service:Product:1" ></u:SourceIndex >
:4:src/ohproduct.cxx:227::OHProduct::sourceIndex: 1
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: SourceXml. Params: <?xml version="1.0"? >
<u:SourceXml xmlns:u="urn:av-openhome-org:service:Product:1" ></u:SourceXml >
:4:src/ohproduct.cxx:219::OHProduct::sourceXML
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: Sender. Params: <?xml version="1.0"? >
<u:Sender xmlns:u="urn:av-openhome-org:service:Receiver:1" ></u:Sender >
:4:src/ohreceiver.cxx:303::OHReceiver::sender
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: TransportState. Params: <?xml version="1.0"? >
<u:TransportState xmlns:u="urn:av-openhome-org:service:Receiver:1" ></u:TransportState >
:4:src/ohreceiver.cxx:311::OHReceiver::transportState
:4:src/ohreceiver.cxx:318::OHReceiver::transportState: Stopped
:4:libupnpp/device/device.cxx:382::UPNP_EVENT_SUBSCRIPTION_REQUEST: urn:av-openhome-org:serviceId:Receiver
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: SetSender. Params: <?xml version="1.0"? >
<u:SetSender xmlns:u="urn:av-openhome-org:service:Receiver:1" >
<Uri >ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b</Uri >
<Metadata ><DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"><item id="0" restricted="True"><dc:title>ENTWICKLERPC</dc:title><res protocolInfo="ohz:*:*:u">ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b</res><upnp:albumArtURI>http://192.168.1.163:49812/icon</upnp:albumArtURI><upnp:class>object.item.audioItem</upnp:class></item></DIDL-Lite></Metadata >
</u:SetSender >
:4:src/ohreceiver.cxx:290::OHReceiver::setSender
:4:src/ohreceiver.cxx:283::OHReceiver::setSender: uri [ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b] meta [<DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" ><item id="0" restricted="True" ><dc:title >ENTWICKLERPC</dc:title ><res protocolInfo="ohz:*:*:u" >ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b</res ><upnp:albumArtURI >http://192.168.1.163:49812/icon</upnp:albumArtURI ><upnp:class >object.item.audioItem</upnp:class ></item ></DIDL-Lite >]
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: SetSourceIndex. Params: <?xml version="1.0"? >
<u:SetSourceIndex xmlns:u="urn:av-openhome-org:service:Product:1" >
<Value >1</Value >
</u:SetSourceIndex >
:4:src/ohproduct.cxx:311::OHProduct::setSourceIndex
:4:src/ohproduct.cxx:244::OHProduct::iSetSourceIndex: current 1 new 1
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: Play. Params: <?xml version="1.0"? >
<u:Play xmlns:u="urn:av-openhome-org:service:Receiver:1" ></u:Play >
:4:src/ohreceiver.cxx:221::OHReceiver::play
:4:src/ohreceiver.cxx:156::OHReceiver::play: executing /usr/bin/sc2mpd
:4:src/execmd-fixed.cpp:454::ExecCmd::startExec: (0|1) /usr/bin/sc2mpd {-d} {-u} {ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b} {-c} {/etc/upmpdcli.conf}
:4:src/ohreceiver.cxx:163::OHReceiver::play: sc2mpd pid 1896
:4:libupnpp/device/device.cxx:382::UPNP_EVENT_SUBSCRIPTION_REQUEST: urn:av-openhome-org:serviceId:Product
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: SourceIndex. Params: <?xml version="1.0"? >
<u:SourceIndex xmlns:u="urn:av-openhome-org:service:Product:1" ></u:SourceIndex >
:4:src/ohproduct.cxx:227::OHProduct::sourceIndex: 1
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: SourceXml. Params: <?xml version="1.0"? >
<u:SourceXml xmlns:u="urn:av-openhome-org:service:Product:1" ></u:SourceXml >
:4:src/ohproduct.cxx:219::OHProduct::sourceXML
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: Sender. Params: <?xml version="1.0"? >
<u:Sender xmlns:u="urn:av-openhome-org:service:Receiver:1" ></u:Sender >
:4:src/ohreceiver.cxx:303::OHReceiver::sender
:4:libupnpp/device/device.cxx:382::UPNP_EVENT_SUBSCRIPTION_REQUEST: urn:av-openhome-org:serviceId:Receiver
:4:libupnpp/device/device.cxx:318::UPNP_CONTROL_ACTION_REQUEST: TransportState. Params: <?xml version="1.0"? >
<u:TransportState xmlns:u="urn:av-openhome-org:service:Receiver:1" ></u:TransportState >
:4:src/ohreceiver.cxx:311::OHReceiver::transportState
:4:src/ohreceiver.cxx:318::OHReceiver::transportState: Playing
:2:libupnpp/device/device.cxx:406::UpnpDevice::callBack: UpnpAcceptSubscription :-109: UPNP_E_INVALID_SID
:4:src/execmd-fixed.cpp:985::ExecCmd::maybereap: got status 0x0xbe9e3d9c
:4:src/ohreceiver.cxx:84::OHReceiver: sc2cmd exited with status 256
:4:src/ohreceiver.cxx:84::OHReceiver: sc2cmd exited with status -1The scmpdcli log file outputs:
:3:sc2src/sc2mpd.cpp:545::scmpdcli: using subnet 192.168.1.0
:4:sc2src/httpgate.cpp:300::audioEater: http
:4:sc2src/httpgate.cpp:310::audioEater: queue 0x82198 HTTP port 8768
:4:sc2src/sc2mpd.cpp:173::=== STARTED ====
:4:sc2src/sc2mpd.cpp:181::=== CONNECTED ====joerg-krause writes
Note, I do not have Python 2 installed. Is it necessary to run sc2mpd?
medoc92 writes
No, I don’t think python is needed for the Receiver mode. What do you have in the config file for the receiver parameters ? http://www.lesbonscomptes.com/upmpdcli/upmpdcli-manual.html#ohmetasleep
medoc92 writes
Also some of the initial exits print stuff to stderr. Could you please try to start the command by hand like:
/usr/bin/sc2mpd -d -u ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b -c /etc/upmpdcli.confand see what it says ?
joerg-krause writes
Not sure what did the trick, but the error disappeared for now. However, I cannot get the Songcast on Windows connect to the receiver.
My receiver parameters:
### Parameters for the sc2mpd Songcast helper command:
sclogfilename = /var/log/scmpdcli.log
scloglevel = 6
scplaymethod = alsa
#schttpport = 8768
scalsadevice = default
# sc2mpd = /usr/bin/sc2mpd
## Parameters tor the Sender/Receiver mode
#scsenderpath = /usr/bin/scmakempdsender
#scsendermpdport = 6700Nevertheless, I tried running sc2mpd by hand:
# /usr/bin/sc2mpd -d -u ohz://239.255.255.250:51972/eabe988a794f90ab64fe70d95271d24b -c /etc/upmpdcli.conf
CONNECTED
CONNECTED
CONNECTEDupplay now says: "Upmpdcli (playing from: Linn-Songcast-PC)", but Songcast on Windows still shows "Disconnected".
joerg-krause writes
Okay, I’ve installed 4.4.190 and I got it "Connected". However, as I start to play I get again:
:4:src/ohreceiver.cxx:318::OHReceiver::transportState: Playing
:4:src/execmd-fixed.cpp:985::ExecCmd::maybereap: got status 0x0xbeb3fd9c
:4:src/ohreceiver.cxx:84::OHReceiver: sc2cmd exited with status 256
:4:src/ohreceiver.cxx:84::OHReceiver: sc2cmd exited with status -1joerg-krause writes
I get some playback if I start sc2mpd manually. However, I got a lot of "REQUEST RESEND" messages and a lot of drop outs. Both the receiver and the sender are using a wired connection.
medoc92 writes
This is weird. I have it working here with the sc2mpd git code running on ubuntu and songcast 4.8.535 both from win10 and win7.
Is songcast set for unicast or multicast ? (In the songcast params on windows)
medoc92 writes
What are you running this on by the way ?
joerg-krause writes
I tried both. I am running this on an ARMv5 board.
medoc92 writes
Maybe validate the situation on a more "classic" machine, and then we’ll see what may be different on the ARM ?
medoc92 writes
Also, this must be a very slow machine ? Maybe try to set sccvttype to NONE or SRC_LINEAR
joerg-krause writes
I installed everything on my host Arch Linux system. I’ve build sc2mpd using the ohbuild method. I got a working audio stream, but the error is also present:
:3:sc2src/workqueue.h:192::alsaqueue: tasks 0 nowakes 0 wsleeps 1 csleeps 0
:2:sc2src/workqueue.h:102::WorkQueue::put:audioqueue: !ok
:2:sc2src/sc2mpd.cpp:352::sc2mpd: queue dead: exiting
:3:sc2src/workqueue.h:192::audioqueue: tasks 1 nowakes 1 wsleeps 1 csleeps 0
:4:src/execmd-fixed.cpp:985::ExecCmd::maybereap: got status 0x0x7fff7a2d274c
:4:src/ohreceiver.cxx:84::OHReceiver: sc2cmd exited with status 256
:4:src/ohreceiver.cxx:84::OHReceiver: sc2cmd exited with status -1joerg-krause writes
Despite of the exit error, it is running fine on my host Linux whereas I got almost no output on my ARMv5 target. top shows about 75% cpu usage. I wonder what sc2mpd makes so cpu hungry, as the snapcast client is running with less than 15% cpu usage.
medoc92 writes
The kind of sample rate adaptation is what determines the CPU usage. From my notes SRC_SINC_BEST_QUALITY uses 25% CPU on a core i7 4770T, SRC_SINC_MEDIUM_QUALITY is around 10%, SRC_SINC_FASTEST is 4-5%. Only SRC_SINC_FASTEST (or lower) is usable on an RPI1
joerg-krause writes
Finally! It’s running without any drop-outs now: * SRC_ZERO_ORDER_HOLD = > 50% * SRC_LINEAR = > 55% * NONE = > ~15%
Using NONE probably means I will have no synchronization, right?
medoc92 writes
Yes, depending on which clock is faster you will have skips or pauses on the slave. If the clocks are close enough, this may not be much of an issue. The high gap between NONE and SRC_LINEAR is probably because of the conversion to floating point and back which libsamplerate needs.
joerg-krause writes
I figured it out why I sc2mpd fails when started by upmpdcli: sc2mpd does not have the permission to access the audio device. upmpdcli runs as user upmpdcli, whereas the audio devices requires root permission. That’s why sc2mpd is working on the command line as it is started as root.
joerg-krause writes
Related to https://github.com/medoc92/sc2mpd/issues/7. However, Buildroot does not have an "audio" group by default.
medoc92 writes
The problem is that I call snd_pcm_open() which is supposed to return < 0 for errors, which does not seem to happen. Do you see anything about snd_pcm_open in the messages ? Something should be printed from https://github.com/medoc92/sc2mpd/blob/master/sc2src/alsadirect.cpp#L184
joerg-krause writes
It does happen:
:2:sc2src/sc2mpd.cpp:186::=== PLAYING ====
:2:sc2src/alsadirect.cpp:184::alsa_init: pcm open default
:2:sc2src/sc2mpd.cpp:206::OhmRcvDrv::Process:audio: samplerate 44100 bitdepth 16 channels 2 samples 1 Halted ? 1
ALSA lib pcm_hw.c:1713:(_snd_pcm_hw_open) Invalid value for card
:2:sc2src/alsadirect.cpp:188::alsa_init: snd_pcm_open default Permission denied
:2:sc2src/workqueue.h:176::setTerminateAndWait:alsaqueue
:2:sc2src/workqueue.h:312::WorkQueue:ok:alsaqueue: not ok m_ok 0 m_workers_exited 0 m_worker_threads size 1
:2:sc2src/alsadirect.cpp:128::alsawriter: waitminsz failed
:2:sc2src/workqueue.h:293::workerExit:alsaqueue
:3:sc2src/workqueue.h:192::alsaqueue: tasks 0 nowakes 0 wsleeps 1 csleeps 0
:2:sc2src/workqueue.h:216::setTerminateAndWait:alsaqueue done
:2:sc2src/workqueue.h:293::workerExit:audioqueue
:2:sc2src/alsadirect.cpp:756::audioEater returningmedoc92 writes
So at least that’s good, we have a diagnostic in this case. Just need an audio group now :)
joerg-krause writes
Yes, I am trying to use mdev now to get the "/dev/snd/" nodes being owned by the audio group.
Something else concerning ALSA: I noticed that sc2mpd never calls snd_pcm_close().
medoc92 writes
sc2mpd gets killed by upmpdcli when switching to another mode, and it does not catch the signal, so, no alsa close. This has never seemed to be an issue ? And, I just checked, I get no indication of what the client app is doing (play/pause/stop), so I can’t really free up the driver until I’m actually disconnected (at which point the process is killed).
joerg-krause writes
I see! If Spotify is e.g. paused, upmpdcli has no knowledge about it, as it just an audio sink.
Actually, it happened when sc2mpd was failing, sometimes the ALSA device was still opened. I wondered why and noticed there is not close(). It didn’t happened since "/dev/snd" is owned by group audio. If it happens again, I’ll open a new issue.
As this issue is solved by adding upmpdcli to the audio group and make "/dev/snd" be owned by the audio group, I’ll close this as solved.