search

eizedev / AirConnect-Synology

Updated AirConnect packages for Synology NAS and Synology Router
https://github.com/philippe44/AirConnect
MIT License
308 stars 14 forks source link

CastDevices disappear after some hours, usually on the next day. #21

Closed eos1d3 closed 3 years ago

eos1d3 commented 3 years ago

Describe the bug CastDevices disappear after some hours, usually on the next day.

To Reproduce Just wait for a long time, usually next day.

Expected behavior CastDevice should always be shown.

Logfiles

[2021-02-24 11:23:58] #### Start preuninst... ####
[2021-02-24 11:24:08] #### Done preuninst ####
[2021-02-24 11:24:08] #### Start postuninst... ####
[11:24:08] User "airconnect" found - deleting it
[11:24:12] "airconnect" user folder "/var/services/homes/airconnect" not found - nothing deleted
[2021-02-24 11:24:15] #### Done postuninst ####
[11:25:45] start-stop-status - Creating "airconnect" user.
[11:25:46] Starting AirConnect ...
[11:25:46] Starting airupnp on 192.168.5.18:49154
[11:25:46.555610] main:1415 Starting airupnp version: v0.2.43.1 (Jan 14 2021 @ 22:18:02)
[11:25:46.555727] main:1423 no config file, using defaults
[11:25:46.557413] Start:1127 Binding to 192.168.5.18:49154
[11:25:46] Starting aircast on 192.168.5.18
[11:25:46.563478] main:966 Starting aircast version: v0.2.43.1 (Jan 14 2021 @ 22:17:01)
[11:25:46.563597] main:974 no config file, using defaults
[11:25:46.563942] Start:727 Binding to 192.168.5.18
[11:25:46] AirConnect successfully started on ip "192.168.5.18"!
[11:25:46.612670] AddCastDevice:664 [0xfb3ff0]: adding renderer (Chromecast Audio)
[11:25:46.612754] AddCastDevice:670 [0xfb3ff0]: creating MAC fb3ffa
[11:25:46.613676] AddCastDevice:664 [0xfb4988]: adding renderer (Black Nest Mini)
[11:25:46.613731] AddCastDevice:670 [0xfb4988]: creating MAC fb4992
[11:25:49.027110] rtsp_thread:356 got RTSP connection 12
[11:25:49.027518] read_line:1219 disconnected on the other end 12
[11:25:49.027576] rtsp_thread:371 RTSP close 12
[11:25:49.028382] rtsp_thread:356 got RTSP connection 9
[11:25:49.028614] read_line:1219 disconnected on the other end 9
[11:25:49.028665] rtsp_thread:371 RTSP close 9
[11:25:52.040972] rtsp_thread:356 got RTSP connection 9
[11:25:52.041166] read_line:1219 disconnected on the other end 9
[11:25:52.041217] rtsp_thread:371 RTSP close 9
[11:25:52.041886] rtsp_thread:356 got RTSP connection 12
[11:25:52.042108] read_line:1219 disconnected on the other end 12
[11:25:52.042163] rtsp_thread:371 RTSP close 12
[22:06:14.743961] CheckAndLock:259 device is NULL
[22:06:14.744124] CheckAndLock:259 device is NULL
[22:06:14.744259] CheckAndLock:259 device is NULL
[22:06:14.744304] CheckAndLock:259 device is NULL
[22:07:08.833721] CheckAndLock:259 device is NULL
[22:07:08.833835] CheckAndLock:259 device is NULL
[22:07:08.833938] CheckAndLock:259 device is NULL
[22:07:08.834080] CheckAndLock:259 device is NULL
[22:08:08.413748] CheckAndLock:259 device is NULL
[22:08:08.413824] CheckAndLock:259 device is NULL
[22:08:08.413917] CheckAndLock:259 device is NULL
[22:08:08.414073] CheckAndLock:259 device is NULL
[04:33:04.941891] mDNSsearchCallback:535 [0xfb3ff0]: removing renderer (Chromecast Audio+) 0
[04:33:04.942297] DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped
[04:33:09.051530] rtsp_thread:356 got RTSP connection 12
[04:33:09.051733] read_line:1219 disconnected on the other end 12
[04:33:09.051799] rtsp_thread:371 RTSP close 12
[04:33:47.393761] AddCastDevice:664 [0xfb3ff0]: adding renderer (Chromecast Audio)
[04:33:47.393859] AddCastDevice:670 [0xfb3ff0]: creating MAC fb3ffa
[04:33:47.393997] mDNSsearchCallback:535 [0xfb3ff0]: removing renderer (Chromecast Audio+) 1
[04:33:47.394305] DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped
[04:33:51.004528] rtsp_thread:356 got RTSP connection 8
[04:33:51.004761] read_line:1219 disconnected on the other end 8
[04:33:51.004831] rtsp_thread:371 RTSP close 8
[08:58:52.195839] mDNSsearchCallback:535 [0xfb4988]: removing renderer (Black Nest Mini+) 0
[08:58:52.196572] DeleteCastDevice:512 [0xfb4988]: Cast device stopped
[08:59:28.247738] AddCastDevice:664 [0xfb3ff0]: adding renderer (Black Nest Mini)
[08:59:28.247856] AddCastDevice:670 [0xfb3ff0]: creating MAC fb3ffa
[08:59:28.248001] mDNSsearchCallback:535 [0xfb3ff0]: removing renderer (Black Nest Mini+) 1
[08:59:28.248510] DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped
[10:36:49.739628] AddCastDevice:664 [0xfb3ff0]: adding renderer (Black Nest Mini)
[10:36:49.739837] AddCastDevice:670 [0xfb3ff0]: creating MAC fb3ffa
[10:36:49.740093] mDNSsearchCallback:535 [0xfb3ff0]: removing renderer (Black Nest Mini+) 1
[10:36:49.740700] DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped
[11:03:52.810809] AddCastDevice:664 [0xfb3ff0]: adding renderer (Black Nest Mini)
[11:03:52.810912] AddCastDevice:670 [0xfb3ff0]: creating MAC fb3ffa
[11:03:52.811050] mDNSsearchCallback:535 [0xfb3ff0]: removing renderer (Black Nest Mini+) 1
[11:03:52.811314] DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped
[11:03:55.673754] AddCastDevice:664 [0xfb3ff0]: adding renderer (Black Nest Mini)
[11:03:55.673836] AddCastDevice:670 [0xfb3ff0]: creating MAC fb3ffa
[11:03:55.673968] mDNSsearchCallback:535 [0xfb3ff0]: removing renderer (Black Nest Mini+) 1
[11:03:55.674626] DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped
[12:32:42.733069] CheckAndLock:259 device is NULL
[12:32:42.733176] CheckAndLock:259 device is NULL
[12:32:42.733292] CheckAndLock:259 device is NULL
[12:32:42.733435] CheckAndLock:259 device is NULL

Hardware (Device on which you are running AirConnect-Synology):

Package (which package from the releases page have you downloaded):

Additional context I have two devices, one Nest Mini and one Chromecast Audio. I found if I do not use both of them, all will be disappeared on the next day. If I keep using Nest Mini, I find it is still there on the next day, but Chromecast Audio is disappeared.

I have to stop the spa in NAS and start it again, and both will work for around one day.

I tried enable multicast routing in Asus router, it won't help at all. These are the settings:

Use DHCP routes: Microsoft (there is RFC3442 option to choose)
Enable multicast routing: Enable
Default IGMP version: IGMP v3 (have v1 and v2 to choose)
Enable Fast Leave: Disable
UDP Proxy (Udpxy): [empty]

I tried to restart Chromecast Audio, but I still can't see its Airplay counterpart.

eizedev commented 3 years ago

Hi @eos1d3 Thanks for the detailed description of your problem and the information, that always helps a lot to narrow down the problem more precisely.

This looks like a multicast problem. IGMP Snooping / Multicast Routing is a little bit difficult to integrate with Airplay. In my local environment i am using IGMP version 2, with version 3 i had similar problems as you. In general you do not need to enable multicast for this purpose if you have all your devices in the same network subnet.

There exists a known bug with your router so that sometimes cast/upnp devices will disappear, for more information please take a look at this chapter in the readme

When players disappear regularly, it might be that your router is filtering out multicast packets. For example and testing, for a Asus AC-RT68U, you have to login by ssh and run echo 0 > /sys/class/net/br0/bridge/multicast_snooping but it does not stay after a reboot.

Maybe there exist new information about this problem for your router, maybe you can find more in google. Also there are a few closed issues in the official airconnect repository about disappearing devices.

btw. in one of the next version you can decide during the installation if you want to install only aircast or airupnp or if you want to install both. I just don't have enough time to finish it at the moment.

René

eos1d3 commented 3 years ago

Thanks! At the very beginning I did not enable multicast at all. But after seeing the problem, I enabled multicast settings but still get the same problem. I will try to use IGMP2 instead.

My all devices are in the same subnet. So that is strange to see the problem. And my problem is not the same as others. Both cast devices can last many hours (usually more than 10 hours). This happens repeatedly at least 3 times/3 days.

I am running Merlin firmware for Asus router, if nothing works I will try the multicast_snooping command with auto-start script in the router.

I will report back later.

eos1d3 commented 3 years ago

Hi, the same problem exists when using IGMP2.

When I tried echo 0 > /sys/class/net/br0/bridge/multicast_snooping but I got the error:

-sh: can't create /sys/class/net/br0/bridge/multicast_snooping: Permission denied

I am using the same and the only Asus router admin account. There is no root account. Any idea for this?

eizedev commented 3 years ago

When I tried echo 0 > /sys/class/net/br0/bridge/multicast_snooping but I got the error:

Hmm, busybox... no sudo, no permission to the devices. don't know the Asus Router, found a few posts about multicast problems through Google: example

You could also open an issue in the official AirConnect repository. The spk Package should not be the problem. I think the Problem is located in a combination of aircast + your network setup. You could also try to run the binaries on a windows/linux computer in the same Network to verify this.

eos1d3 commented 3 years ago

Right, there is no sudo. I login Synology NAS again with account name, now it still shows 

$cat /sys/class/net/br0/bridge/multicast_snooping
cat: /sys/class/net/br0/bridge/multicast_snooping: No such file or directory

Anyway, I did find something. I stopped the SPK and I run aircast-win on my Windows 10 machine in the same network, it has been more than 2 days and cast devices are still there. So original AirConnect on Windows platform does not have this issue.

I have two cast devices, Nest Mini and Chromecast Audio, I see only one entry of this after two days in AirConnect log file.

[03:12:02.169] mDNSsearchCallback:527 [022B8BF8]: removing renderer (Chromecast Audio+) 36483040

And unlike SPK version, there is NO DeleteCastDevice:512 [0xfb3ff0]: Cast device stopped after receiving mDNSsearchCallback.

eizedev commented 3 years ago

It looks like some mDNS announces are not relayed. These mDNS packages have a time to live (ttl) configured but i don't know long the timeout is set for. Do you have any managed switches in your environment? Or any differences in the connection from your windows pc and your NAS to your router? (Windows PC -> XX -> Router -> IPhone | NAS -> XX -> Router -> IPhone). I also had a miss configuration in my environment setup in the past (Repeater in combination with a missing multicast configuration on my managed switches).

I think it would be best if you inform the developer @philippe44 of AirConnect directly (open an issue), so that he can check it again. not that there is a bug in the aircast package.

You could also try to raise the logging level to sdebug instead of the normal command line execution. Maybe he can then also identify your problem more precisely if you upload the logfile.

/volume1/@appstore/AirConnect/aircast -b [synology device local ip] -l 1000:2000 -x "/volume1/@appstore/AirConnect/config-cast.xml" -z -f "/var/log/airconnect.log" -d all=sdebug

eos1d3 commented 3 years ago

I will keep testing for a while. Original AirConnect is not problem free. It won't disappear, but when I try to connect the devices, they just have no response.

I have a managed switch with VLAN support. But I will try router setting first as I just find it has Enable IGMP Snoopingoption in Wireless setting, not in Lan setting. It was enabled before, so shall I disable it to see any difference?

eos1d3 commented 3 years ago

The problem may be caused by AirCast 0.2.44.0 because I also found SPK version can't add cast device back after power reset. See https://github.com/philippe44/AirConnect/issues/330

I am running aircast-x86-64 0.2.44.1 directly on my DS918+ without using SPK. It has been running more than 20 hours and everything is OK.

I will run it for some more days in order to confirm it is caused by 0.2.44.0.

eos1d3 commented 3 years ago

Hi, I am still running AirCast 0.2.44.1 (not SPK version) for 2 days in my Synology NAS. Both cast devices are still working. So it is very likely the problem is caused by 0.2.44.0.

eizedev commented 3 years ago

@eos1d3 Thanks for the debugging and clarification! You are right, the problem was introduced in 0.2.43.0, for more information please check this issue: https://github.com/philippe44/AirConnect/issues/330

I have update the spk package to the newest version 0.2.44.1, you can find the release here: https://github.com/eizedev/AirConnect-Synology/releases/tag/0.2.44.1-20210308

Please give a short feedback if it works.

eos1d3 commented 3 years ago

0.2.44.1 fixes the issue after further test. Thanks!