Source unable to connect to sink (miraclecast-sinkctl). Only ADD is successful, PROV, GO NEG, CONNECT events doesnt happen

[sunielmahesh]

Hi Alberto Fanjul and All,

1. I am using miraclecast on my sink device to source my mobile device, here are my setup details:

Sink Device: Device running yocto based distribution on Linux v6.1.50 with miraclecast. Its an embedded device based on ALLWINNER A33 SOC with Realtek RTL88x2BU wifi chipset.

Source Device: Andriod mobile device

2. I am able to follow the miraclecast documentation and I can see my source(mobile) device getting added via miraclecast-sinkctl

[07/08/24 - 21:36:23.008.514] [ADD] Link: 3 [sinkctl] # run 3 [07/08/24 - 21:36:32.008.585] now running on link 3 [07/08/24 - 21:36:34.008.729] [ADD] Peer: 82:7b:18:56:e1:6d@3 [sinkctl] # list LINK INTERFACE FRIENDLY-NAME MANAGED
3 wlan0 yes

LINK PEER-ID FRIENDLY-NAME CONNECTED 3 82:7b:18:56:e1:6d@3 IN1b no

1 peers and 1 links listed.

3. The steps in miracelcast-sinkctl for a connection are ADD, PROV, GO NEG, CONNECT.

ADD part of the code is fine but for some reason the relevant code in ctl/sinkctl.c never kickoff: PROV => ctl_fn_peer_provision_discovery GO NEG => ctl_fn_peer_go_neg_request CONNECT => ctl_fn_peer_connected

Can you please guide/advice on the above issue: I am attaching the following logs for your reference: wifid.log sink.log journalctl.log dbus.log

sink.log wifid.log journalctl.log dbus.log

[sunielmahesh]

I am suspecting that something wrong at the dbus level. the relevant call back functions are not getting triggered.

[chrisvollorenew]

@albfan I am also interested in knowing the answer to this issue! Thank you!

[albfan]

From attached logs looks like you never start to source the screen.

That negotiation is started from source device

First result on google:

https://www.avaccess.com/blogs/guides/what-is-miracast/#:~:text=How%20to%20use%20Miracast%20on,instructions%20to%20complete%20the%20connection.

[sunielmahesh]

Thanks for the link, i have gone through it and i am in sync with what it says.

This is how my test setup is:

SINK device (Allwinner A33 based projector with Realtek wifi chipset) SOURCE Device (phone)

when i run miraclecast-sinkctl on the SINK device, it is scanning and adding the source devices - upto this it is fine (m2.jpg, m3.jpg)

The next step as per my understanding:

SINK device should do PROV(provisioning), so that sink device will appear as an entry(with device id) on SOURCE device and then the rest follows:

I cant see any provisioning happenning, meaning no SINK device entry happenning on SOURCE device, SOURCE device cant see the sink device.

please correct me, if my understanding is wrong.

attaching some screen shots for reference.

The phone(SOURCE) id is Chakri's-a35

m1.jpg => smart view on samsung SOURCE device m2.jpg => sinkctl log on SINK device m3.jpg => sinkctl log on SINK device

[albfan]

You need to specify what interface you will use in sink:

In your case

run 3

or

bind 3

[sunielmahesh]

it is run 3

[albfan]

The only difference with bind is it allows hotplugged interfaces to directly be "runned" when connected

Remember to close issue if It is resolved

[sunielmahesh]

bind 3 and run 3 both behaves the same way. The souce device(mobile) gets ADDED, but a connection is not formed as explained above.

I cant see my target(sink) appear on source side miraclecast equivalent.

looks like sink is able to ADD sources, but not able to send PROV, GO NEG, CONNECT.

anymore suggestions or area i need to look on, please suggest. Thanks

the below is a snapshot of the sinkctl running on sink device.

[albfan]

Bind just do a run command once a new interface, like a wifi USB dongle is connected.

In your screenshot there's no run or bind command executed.

After that, your source device should see the sink (miracle is the default name)

Then your source device should start the GO NEG

[sunielmahesh]

i am doing a run command on sink side, but source cant see the sink.

[albfan]

Those messages "scan abort!! BusyTraffic" looks related.

That's why collect all logs (miracle-wifid, miracle-sinkctl, journalctl, dbus) with time are relevant.

run command starts a P2PScanning, which should discover the sink on your source. That step is failing here. We need the logs to identify the problem

[sunielmahesh]

Please find the attached logs and screenshots. Thanks

wifid.log sink.log journal.log dbus.log

as shown below, they are two sources(mobiles):

[albfan]

I would suggest to use command set-friendly-name and --use-dev

Definitely "scan abort BussyTraffic" is related but I'm unsure why. Probably logs from mobile communication would help, but you need a rooted device for that

[chrisvollorenew]

@albfan how about wireshark?

Also, could a firewall be preventing the connection? Are there any ports that could be blocked causing the issue?

[sunielmahesh]

Hi again @albfan

please find the attached andriod phone log. grabbed the log via developer options, usb debugging and adb

adb.log

[albfan]

But that adb log starts at 21:28, we cannot see anything from a temptative attempt that day at 14:03

Filtering journal.log I think we see the cause:

$ grep miracle journal.log 
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: Successfully initialized wpa_supplicant
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Match already configured
Jul 18 14:03:07 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: kernel reports: Registration to specific type not supported
Jul 18 14:03:36 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: P2P-DEVICE-FOUND 82:d2:b5:26:82:13 p2p_dev_addr=82:d2:b5:26:82:13 pri_dev_type=10-0050F204-5 name='IN1b' config_methods=0x188 dev_capab=0x25 group_capab=0x0 wfd_dev_info=0x00101c440032 vendor_elems=1 new=1
Jul 18 14:03:39 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: P2P-DEVICE-FOUND 4a:7a:08:61:99:63 p2p_dev_addr=4a:7a:08:61:99:63 pri_dev_type=10-0050F204-5 name='Redmi Note 11T 5G' config_methods=0x188 dev_capab=0x25 group_capab=0x0 wfd_dev_info=0x00101c440032 vendor_elems=1 new=1
Jul 18 14:05:29 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: wlan0: Failed to get BSSID
Jul 18 14:05:29 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Jul 18 14:05:29 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: CTRL_IFACE: Detach monitor that cannot receive messages: /tmp/.miracle-wpas-3412-2\x00
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: P2P-FIND-STOPPED
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: P2P-DEVICE-LOST p2p_dev_addr=4a:7a:08:61:99:63
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: P2P-DEVICE-LOST p2p_dev_addr=82:d2:b5:26:82:13
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: CTRL_IFACE: Detach monitor that cannot receive messages: /tmp/.miracle-wpas-3412-1\x00
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Jul 18 14:06:11 r16-renew-vista-e miracle-wifid-wlan0-3[3419]: wlan0: CTRL-EVENT-TERMINATING

Most probably your network interface nl80211 do not support features needed.

this is a normal journal.log

jul 20 11:43:58 fedora sudo[227061]:  alberto : TTY=pts/7 ; PWD=/home/alberto ; USER=root ; COMMAND=/usr/bin/miracle-wifid --log-level trace --log-date-time --ip-binary /usr/sbin/ip
jul 20 11:43:58 fedora miracle-wifid-wlp0s20f3-2[227067]: Successfully initialized wpa_supplicant
jul 20 11:43:58 fedora miracle-wifid-wlp0s20f3-2[227067]: wlp0s20f3: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=WORLD
jul 20 11:44:37 fedora sudo[227220]:  alberto : TTY=pts/11 ; PWD=/home/alberto ; USER=root ; COMMAND=/usr/bin/miracle-sinkctl --log-level trace --log-journal-level trace --log-date-time
jul 20 11:44:45 fedora miracle-wifid-wlp0s20f3-2[227067]: wlp0s20f3: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=ES
jul 20 11:45:00 fedora miracle-wifid-wlp0s20f3-2[227067]: P2P-DEVICE-FOUND aa:bb:43:ce:a7:e1 p2p_dev_addr=aa:bb:43:ce:a7:e1 pri_dev_type=10-0050F204-5 name='Phone' config_methods=0x188 dev_capab=0x25 group_capab=0x0 wfd_dev_info=0x00101c440032 vendor_elems=1 new=1
jul 20 11:45:02 fedora miracle-wifid-wlp0s20f3-2[227067]: P2P-INVITATION-RECEIVED sa=aa:bb:43:ce:a7:e1 go_dev_addr=aa:bb:43:ce:a7:e1 bssid=aa:bb:43:ce:a7:e1 unknown-network
jul 20 11:45:03 fedora miracle-wifid-wlp0s20f3-2[227067]: P2P-GO-NEG-REQUEST aa:bb:43:ce:a7:e1 dev_passwd_id=4 go_intent=15
jul 20 11:45:03 fedora miracle-wifid-wlp0s20f3-2[227067]: P2P-FIND-STOPPED

Probably that fail for your discovery kernel reports: Registration to specific type not supported prevents your phone to see your miraclecast running instance as a possible sink

Did you check your hardware with test-hardware-capabilities.sh? See wiki for more info

[sunielmahesh]

Hi @albfan we are suspecting some issues at the wifi driver side. closing the issue as of now. will post observations once we find a solution. Thanks for the support