search

grover / homebridge-dacp

Remotely control Apple TV and iTunes via HomeKit.
MIT License
151 stars 14 forks source link

Fatal error browsing for DACP services \ {"code":-3008 #10

Closed AntoGi closed 6 years ago

AntoGi commented 6 years ago

Hi.. Happy new year to you and thx for developing on this project.

Hope I‘m not raising a duplicate to another issue, but encountered this tonight when trying to setup my apple tv 4gen for homebridge. Was able to successfully pair the apple tv but then it always would end in error saying Apple TV is down.

Thx for looking into it!

[2018-1-3 00:47:08] [DACP] [2018-1-3 00:49:08] [DACP] Starting DACP browser... [2018-1-3 00:49:08] [DACP] Fatal error browsing for DACP services: [2018-1-3 00:49:08] [DACP] [2018-1-3 00:49:08] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-3 00:49:08] [DACP] [2018-1-3 00:49:08] [DACP] Restarting MDNS browser for DACP in 120 seconds

grover commented 6 years ago

Any more info? Any other plugins running? WiFi or Ethernet? What system? I haven't seen this and don't know what could cause it.

AntoGi commented 6 years ago

Hi Hope this info helps System: Synology NAS OS: DSM 6.1.4 Connection: Ethernet to router. Node JS 4.8.4 Homebridge 1.0.4 running in Docker

Other plugins run just fine (like homematic etc). Home app discovers all devices. Apple TV remote gets recognized on apple tv, but after succesfull pairing the log says:

Fatal error browsing for DACP services: [2018-1-4 20:27:32] [DACP] [2018-1-4 20:27:32] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-4 20:27:32] [DACP] [2018-1-4 20:27:32] [DACP] Restarting MDNS browser for DACP in 120 seconds. [2018-1-4 20:27:32] [DACP] [2018-1-4 20:27:32] [DACP] The accessory Apple TV (Living room) is down

AntoGi commented 6 years ago

Hi Just saw your reply on another issue. Searched for another NodeJS version, maybe this would be the cause for the problem. Uninstalled NodeJs 4 and installed v8.2.1.

Unfortunately problem remains.

Any specific port DACP must be able to use?

2018-1-5 22:37:17] [DACP] Found accessory in config: "Apple TV (Living room)" [2018-1-5 22:37:17] [DACP] Initializing platform accessory 'Apple TV (Living room)'... [2018-1-5 22:37:17] Loading 0 accessories... [2018-1-5 22:37:17] [DACP] Starting DACP browser... [2018-1-5 22:37:17] [DACP] Fatal error browsing for DACP services: [2018-1-5 22:37:17] [DACP] [2018-1-5 22:37:17] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-5 22:37:17] [DACP] [2018-1-5 22:37:17] [DACP] Restarting MDNS browser for DACP in 120 seconds. [2018-1-5 22:37:17] [DACP] [2018-1-5 22:37:17] [DACP] The accessory Apple TV (Living room) is down.

grover commented 6 years ago

It needs MDNS to work. But it wouldn’t have paired without it in the first place. Did you make any changes after/during pairing?

grover commented 6 years ago

Just found this: https://github.com/agnat/node_mdns/issues/130

I guess there’s a patch to be made to the MDNS browsing code.

AntoGi commented 6 years ago

Hi Thx for looking into it! Yes, I thought so too. If there would be a network or port problem, this would probanly be a problem for the pairing and discovery too, but it wasn‘t. Didn‘t make any chances between adding and pairing.

Thx for helping!

grover commented 6 years ago

I just pushed 0.7.6 to npm. I'm not sure if that fixes it as I already had a custom resolver sequence in there. Could you please verify?

AntoGi commented 6 years ago

Will do asap.. will let you know!

Thx a million!

AntoGi commented 6 years ago

No luck.. upgraded and restarted homebridge. Same error occurs. I have to assume it has something to do with this running on my diskstation and homebridge in docker. Weird that the first steps for pairing seem to work.

grover commented 6 years ago

Hmm. If it's not too much to ask, could you reset your homebridge configuration and run the plugin with a new remote without pairing key? I don't really think that makes a difference due to the code structure, but who knows.

AntoGi commented 6 years ago

Okay.. so removed the other plug in I used and cleared the config. After restart, this is what log looks like. Hope this helps. Will now add dacp config and report back

[2018-1-6 20:00:46] [homebridge-config-ui-x] Logs cleared by Administrator. [2018-1-6 20:00:53] Got SIGTERM, shutting down Homebridge... [2018-1-6 20:00:55] [homebridge-config-ui-x] Console is listening on port 8581. WARNING The program 'node' uses the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see WARNING The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see [2018-1-6 20:01:02] Plugin /homebridge/node_modules/homebridge-homematic does not contain a package.json. WARNING The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see [2018-1-6 20:01:02] Loaded plugin: homebridge-dacp [2018-1-6 20:01:02] Registering platform 'homebridge-dacp.DACP' [2018-1-6 20:01:02] --- [2018-1-6 20:01:02] Loaded plugin: homebridge-dummy [2018-1-6 20:01:02] Registering accessory 'homebridge-dummy.DummySwitch' [2018-1-6 20:01:02] --- [2018-1-6 20:01:02] Loaded plugin: homebridge-config-ui-x [2018-1-6 20:01:02] Registering platform 'homebridge-config-ui-x.config' [2018-1-6 20:01:02] --- [2018-1-6 20:01:02] Loaded config.json with 0 accessories and 0 platforms. [2018-1-6 20:01:02] --- [2018-1-6 20:01:02] Loading 0 platforms... [2018-1-6 20:01:02] Loading 0 accessories..

AntoGi commented 6 years ago

Now changed config to reflect:

"platforms": [
    {
        "platform": "DACP",
        "devices": [
            {
                "name": "AppleTV"
            }
        ]
    }
]

}

After restart, this is the log

[2018-1-6 20:09:52] Loading 1 platforms... [2018-1-6 20:09:52] [DACP] Initializing DACP platform... [2018-1-6 20:09:52] [DACP] DACP Platform Plugin Loaded [2018-1-6 20:09:52] [DACP] Found accessory in config: "AppleTV" [2018-1-6 20:09:52] [DACP] [2018-1-6 20:09:52] [DACP] Skipping creation of the accessory "AppleTV" because it doesn't have a pairing code or [2018-1-6 20:09:52] [DACP] service name yet. You need to pair the device/iTunes, reconfigure and restart homebridge. [2018-1-6 20:09:52] [DACP] [2018-1-6 20:09:52] [DACP] Beginning remote control announcements for the accessory "AppleTV". [2018-1-6 20:09:52] [DACP] [2018-1-6 20:09:52] [DACP] Use passcode 7031 to pair with this remote control. [2018-1-6 20:09:52] [DACP] [2018-1-6 20:09:52] Loading 0 accessories...

AntoGi commented 6 years ago

Let me know what to do next...

grover commented 6 years ago

Does it start now without the error you reported?

AntoGi commented 6 years ago

Yes, it‘s here..:-(

2018-1-6 20:11:52] [DACP] Starting DACP browser... [2018-1-6 20:11:52] [DACP] Fatal error browsing for DACP services: [2018-1-6 20:11:52] [DACP] [2018-1-6 20:11:52] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-6 20:11:52] [DACP] [2018-1-6 20:11:52] [DACP] Restarting MDNS browser for DACP in 120 seconds. [2018-1-6 20:11:52] [DACP] [2018-1-6 20:13:52] [DACP] Starting DACP browser... [2018-1-6 20:13:53] [DACP] Fatal error browsing for DACP services: [2018-1-6 20:13:53] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-6 20:13:53] [DACP] [2018-1-6 20:13:53] [DACP] [2018-1-6 20:13:53] [DACP] Restarting MDNS browser for DACP in 120 seconds. [2018-1-6 20:13:53] [DACP] [2018-1-6 20:15:53] [DACP] Starting DACP browser... [2018-1-6 20:15:53] [DACP] Fatal error browsing for DACP services: [2018-1-6 20:15:53] [DACP] [2018-1-6 20:15:53] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-6 20:15:53] [DACP] [2018-1-6 20:15:53] [DACP] Restarting MDNS browser for DACP in 120 seconds. [2018-1-6 20:15:53] [DACP] [2018-1-6 20:17:53] [DACP] Starting DACP browser... [2018-1-6 20:17:53] [DACP] Fatal error browsing for DACP services: [2018-1-6 20:17:53] [DACP] [2018-1-6 20:17:53] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-6 20:17:53] [DACP] [2018-1-6 20:17:53] [DACP] There were 5 failures in the past 600s. Giving up. [2018-1-6 20:17:53] [DACP] [2018-1-6 20:17:53] [DACP] Restarting homebridge might fix the problem. If not, file an issue at https://github.com/grover/homebridge-dacp. [2018-1-6 20:17:53] [DACP] [2018-1-6 20:20:51] [DACP] Completed pairing for "AppleTV": [2018-1-6 20:20:51] [DACP] [2018-1-6 20:20:51] [DACP] { [2018-1-6 20:20:51] [DACP] "name": "AppleTV", [2018-1-6 20:20:51] [DACP] "pairing": "...", [2018-1-6 20:20:51] [DACP] "serviceName": "..." [2018-1-6 20:20:51] [DACP] } [2018-1-6 20:20:51] [DACP] [2018-1-6 20:20:51] [DACP] Please add the above block to the accessory in your homebridge config.json [2018-1-6 20:20:51] [DACP] [2018-1-6 20:20:51] [DACP] YOU MUST RESTART HOMEBRIDGE AFTER YOU ADDED THE ABOVE LINES OR THE ACCESSORY [2018-1-6 20:20:51] [DACP] WILL NOT WORK. [2018-1-6 20:20:51] [DACP]

grover commented 6 years ago

:(

AntoGi commented 6 years ago

If it helps at all. The remote is now visible on the apple tv (along all the others from previous attempts). When I restart homebrigde, the remote ready to be paired (AppleTV) disapears and comes back when homebridge is ready again.

2018-1-6 20:24:46] Got SIGTERM, shutting down Homebridge... [2018-1-6 20:24:48] [homebridge-config-ui-x] Console is listening on port 8581. WARNING The program 'node' uses the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see WARNING The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see [2018-1-6 20:24:54] Plugin /homebridge/node_modules/homebridge-homematic does not contain a package.json. WARNING The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see [2018-1-6 20:24:55] Loaded plugin: homebridge-dacp [2018-1-6 20:24:55] Registering platform 'homebridge-dacp.DACP' [2018-1-6 20:24:55] --- [2018-1-6 20:24:55] Loaded plugin: homebridge-dummy [2018-1-6 20:24:55] Registering accessory 'homebridge-dummy.DummySwitch' [2018-1-6 20:24:55] --- [2018-1-6 20:24:55] Loaded plugin: homebridge-config-ui-x [2018-1-6 20:24:55] Registering platform 'homebridge-config-ui-x.config' [2018-1-6 20:24:55] --- [2018-1-6 20:24:55] Loaded config.json with 0 accessories and 1 platforms. [2018-1-6 20:24:55] --- [2018-1-6 20:24:55] Loading 1 platforms... [2018-1-6 20:24:55] [DACP] Initializing DACP platform... [2018-1-6 20:24:55] [DACP] DACP Platform Plugin Loaded [2018-1-6 20:24:55] [DACP] Found accessory in config: "AppleTV" [2018-1-6 20:24:55] [DACP] [2018-1-6 20:24:55] [DACP] Skipping creation of the accessory "AppleTV" because it doesn't have a pairing code or [2018-1-6 20:24:55] [DACP] service name yet. You need to pair the device/iTunes, reconfigure and restart homebridge. [2018-1-6 20:24:55] [DACP] [2018-1-6 20:24:55] [DACP] Beginning remote control announcements for the accessory "AppleTV". [2018-1-6 20:24:55] [DACP] [2018-1-6 20:24:55] [DACP] Use passcode 3641 to pair with this remote control. [2018-1-6 20:24:55] [DACP] [2018-1-6 20:24:55] Loading 0 accessories...

[2018-1-6 20:24:55] [DACP] Starting DACP browser... [2018-1-6 20:24:55] Homebridge is running on port 51826. [2018-1-6 20:24:55] [DACP] Fatal error browsing for DACP services: [2018-1-6 20:24:55] [DACP] [2018-1-6 20:24:55] [DACP] Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"} [2018-1-6 20:24:55] [DACP] [2018-1-6 20:24:55] [DACP] Restarting MDNS browser for DACP in 120 seconds. [2018-1-6 20:24:55] [DACP] [2018-1-6 20:25:01] [homebridge-config-ui-x] Administrator successfully logged i

AntoGi commented 6 years ago

So.. remote is made visible to apple tv, pairing also.. but everything after that fails..

AntoGi commented 6 years ago

Deactivated any bonjour service running on the Synology and rebooted the NAS.. still no luck..

grover commented 6 years ago

Hey, I just saw that you're using Node JS 4.8.4 - could you upgrade to 8.9.3? That's the version that I develop upon and it seems as if the low level interface between the mdns library and node.js may have changed.

grover commented 6 years ago

Also what's the version of homebridge in the docker container? 1.0.4 is not the homebridge version, the current one is 0.4.33.

AntoGi commented 6 years ago

Hi Homebridge version is Version 0.4.33. Unfortunately, I‘m afraid I‘m dependent on the version of NodeJS which is made available by synology. Currently it looks like they only provide v8.2.1 :-(

Guess I‘ll have to wait until the release 8.9.3

AntoGi commented 6 years ago

Just realized that homebridge is running within docker (sorry, new to docker so I did not think about it earlier). So therefore there should not be a dependency on the NodeJS version installed in DSM. Actually removed all nodeJS and Homebridge still runs fine. So I now have to dind out what version of NodeJS is running within Docker and then upgrade to 8.9.3

AntoGi commented 6 years ago

So, figured out that nodeJS in the container I use to run Homebrigde uses NodeJS 8.9.3. Today upgraded to Homebridge 0.4.35.

If it helps, this is the docker container I use to run Homebridge: https://hub.docker.com/r/oznu/homebridge/

charlestephen commented 6 years ago

I have this same problem using the same Docker but on Node v8.9.4. I've got my Docker container running in host networking mode to solve other issues and I'm having the exact same issue. I can initially pair, but can't do anything thereafter.

quacktacular commented 6 years ago

Just a me too. Error 3008 in a docker container with host networking.

grover commented 6 years ago

I've updated homebridge-dacp to use the bonjour package instead of the previously used mdns package. Since I plan to release 0.8.0 next week I'm looking for early feedback if this also solves the docker issues you all have been seeing.

Could you please verify by:

and running it again? Feedback appreciated.

quacktacular commented 6 years ago

Hey thanks for the update. I installed from GitHub, and when start homebridge I get the same error, followed by a type error.

[2018-2-18 15:45:26] [DACP] Starting DACP browser...
[2018-2-18 15:45:26] Homebridge is running on port 51004.
[2018-2-18 15:45:26] [DACP] Fatal error browsing for DACP services:
[2018-2-18 15:45:26] [DACP] 
[2018-2-18 15:45:26] [DACP]   Error: {"code":-3008,"errno":-3008,"syscall":"getaddrinfo"}
[2018-2-18 15:45:26] [DACP] 
[2018-2-18 15:45:26] [DACP] Restarting MDNS browser for DACP in 120 seconds.
[2018-2-18 15:45:26] [DACP] 
[2018-2-18 15:45:26] [DACP] The accessory Apple TV is down.
[2018-2-18 15:45:26] [DACP] Fatal error while talking to Apple TV:
[2018-2-18 15:45:26] [DACP] 
[2018-2-18 15:45:26] [DACP]   Error: TypeError: Cannot read property 'host' of undefined
    at DacpClient._withConnection (/homebridge/node_modules/homebridge-dacp/src/dacp/DacpClient.js:205:67)
    at DacpClient.disconnect (/homebridge/node_modules/homebridge-dacp/src/dacp/DacpClient.js:48:23)
    at DacpAccessory.accessoryDown (/homebridge/node_modules/homebridge-dacp/src/DacpAccessory.js:165:22)
    at _accessories.forEach.accessory (/homebridge/node_modules/homebridge-dacp/src/index.js:116:17)
    at Array.forEach (<anonymous>)
    at DacpPlatform._onDacpBrowserError (/homebridge/node_modules/homebridge-dacp/src/index.js:115:23)
    at emitOne (events.js:116:13)
    at DacpBrowser.emit (events.js:211:7)
    at Browser._browser.on.error (/homebridge/node_modules/homebridge-dacp/src/dacp/DacpBrowser.js:37:12)
    at emitTwo (events.js:126:13)
    at Browser.emit (events.js:214:7)
    at on_resolver_done (/homebridge/node_modules/mdns/lib/browser.js:28:14)
    at next (/homebridge/node_modules/mdns/lib/browser.js:100:7)
    at /homebridge/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11
    at getaddrinfo_complete (/homebridge/node_modules/mdns/lib/resolver_sequence_tasks.js:112:7)
    at GetAddrInfoReqWrap.oncomplete (/homebridge/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9)
[2018-2-18 15:45:26] [DACP] 
(node:2312) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 2): TypeError: Cannot read property 'host' of undefined
(node:2312) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

Also I think the 3008 error is coming from src/dacp/DacpBrowser.js, but the code still seems to reference mdns (unless the lib was changed somewhere higher up the chain haha).

    const ResolverSequence = [
      mdns.rst.DNSServiceResolve(),
      'DNSServiceGetAddrInfo' in mdns.dns_sd ? mdns.rst.DNSServiceGetAddrInfo() : mdns.rst.getaddrinfo({ families: [0] }),
      mdns.rst.makeAddressesUnique()
    ];

    this._browser = mdns.createBrowser(
      mdns.tcp(ServiceName),
      { resolverSequence: ResolverSequence });
grover commented 6 years ago

You're still using the old version. Please use the latest code from github - see the instructions above. If needed, please uninstall the old version first using npm uninstall -g homebridge-dacp.

quacktacular commented 6 years ago

Thanks! I actually did do that, and have the same results.. I confirmed I have the latest version by confirming the new example and changelog entries are present in the installed version. Is there another branch?

The code I was referencing is not from my machine, its still live on GitHub https://github.com/grover/homebridge-dacp/blob/master/src/dacp/DacpBrowser.js

Sorry if I've missed something..

grover commented 6 years ago

Turns out I missed to push the change. Please try again. Sorry.

quacktacular commented 6 years ago

Alright got the new version installed. Definitely using bonjour instead of the mdns package now, but sadly it looks like bonjour still makes a call to getaddrinfo.

[2018-2-18 16:29:13] [DACP] Starting DACP browser...
[2018-2-18 16:29:14] Homebridge is running on port 51004.
[2018-2-18 16:29:14] [DACP] The accessory Apple TV is announced.
[2018-2-18 16:29:14] [DACP] Attempting to reconnect to Apple TV in 0.1 seconds.
[2018-2-18 16:29:14] [DACP] Connecting to Apple TV (Living.local:3689)
[2018-2-18 16:29:14] [DACP] Creating status connection to Living.local:3689
[2018-2-18 16:29:15] [DACP] Fatal error while talking to Apple TV:
[2018-2-18 16:29:15] [DACP] 
[2018-2-18 16:29:15] [DACP]   Error: { error: 
   { Error: getaddrinfo ENOTFOUND living.local living.local:3689
    at errnoException (dns.js:50:10)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:92:26)
     code: 'ENOTFOUND',
     errno: 'ENOTFOUND',
     syscall: 'getaddrinfo',
     hostname: 'living.local',
     host: 'living.local',
     port: '3689' },
  response: undefined,
  options: 
   { encoding: null,
     url: URL {
        href: 'http://living.local:3689/login?pairing-guid=0xD726D61018D31EDF',
        origin: 'http://living.local:3689',
        protocol: 'http:',
        username: '',
        password: '',
        host: 'living.local:3689',
        hostname: 'living.local',
        port: '3689',
        pathname: '/login',
        search: '?pairing-guid=0xD726D61018D31EDF',
        searchParams: URLSearchParams { 'pairing-guid' => '0xD726D61018D31EDF' },
        hash: '' },
     headers: 
      { Accept: '*/*',
        'Viewer-Only-Client': '1',
        'Client-DAAP-Version': '3.12',
        'Client-ATV-Sharing-Version': '1.2',
        'Client-iTunes-Sharing-Version': '3.10',
        'User-Agent': 'TVRemote/186 CFNetwork/808.1.4 Darwin/16.1.0' },

nt: 
      Agent {
        domain: null,
        _events: [Object],
        _eventsCount: 1,
        _maxListeners: undefined,
        defaultPort: 80,
        protocol: 'http:',
        options: [Object],
        requests: {},
        sockets: [Object],
        freeSockets: {},
        keepAliveMsecs: 1000,
        keepAlive: true,
        maxSockets: 1,
        maxFreeSockets: 1 } } }
[2018-2-18 16:29:15] [DACP] 
[2018-2-18 16:29:15] [DACP] Attempting to reconnect to Apple TV in 0.2 seconds.
[2018-2-18 16:29:15] [DACP] [Apple TV] Connection to DACP server failed: { error: 
   { Error: getaddrinfo ENOTFOUND living.local living.local:3689
    at errnoException (dns.js:50:10)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:92:26)
     code: 'ENOTFOUND',
     errno: 'ENOTFOUND',
     syscall: 'getaddrinfo',
     hostname: 'living.local',
     host: 'living.local',
     port: '3689' },
  response: undefined,
  options: 
   { encoding: null,
     url: URL {
        href: 'http://living.local:3689/login?pairing-guid=0xD726D61018D31EDF',
        origin: 'http://living.local:3689',
        protocol: 'http:',
        username: '',
        password: '',
        host: 'living.local:3689',
        hostname: 'living.local',
        port: '3689',
        pathname: '/login',
        search: '?pairing-guid=0xD726D61018D31EDF',
        searchParams: URLSearchParams { 'pairing-guid' => '0xD726D61018D31EDF' },
        hash: '' },
     headers: 
      { Accept: '*/*',
        'Viewer-Only-Client': '1',
        'Client-DAAP-Version': '3.12',
        'Client-ATV-Sharing-Version': '1.2',
        'Client-iTunes-Sharing-Version': '3.10',
        'User-Agent': 'TVRemote/186 CFNetwork/808.1.4 Darwin/16.1.0' },

nt: 
      Agent {
        domain: null,
        _events: [Object],
        _eventsCount: 1,
        _maxListeners: undefined,
        defaultPort: 80,
        protocol: 'http:',
        options: [Object],
        requests: {},
        sockets: [Object],
        freeSockets: {},
        keepAliveMsecs: 1000,
        keepAlive: true,
        maxSockets: 1,
        maxFreeSockets: 1 } } }
(node:3633) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 1): IllegalStateError: Backoff in progress.
(node:3633) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
[2018-2-18 16:29:15] [DACP] Connecting to Apple TV (Living.local:3689)
[2018-2-18 16:29:15] [DACP] Creating status connection to Living.local:3689
[2018-2-18 16:29:16] [DACP] Fatal error while talking to Apple TV:
[2018-2-18 16:29:16] [DACP] 
[2018-2-18 16:29:16] [DACP]   Error: { error: 
   { Error: getaddrinfo ENOTFOUND living.local living.local:3689
    at errnoException (dns.js:50:10)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:92:26)
     code: 'ENOTFOUND',
     errno: 'ENOTFOUND',
     syscall: 'getaddrinfo',
     hostname: 'living.local',
     host: 'living.local',
     port: '3689' },
  response: undefined,
  options: 
   { encoding: null,
     url: URL {
        href: 'http://living.local:3689/login?pairing-guid=0xD726D61018D31EDF',
        origin: 'http://living.local:3689',
        protocol: 'http:',
        username: '',
        password: '',
        host: 'living.local:3689',
        hostname: 'living.local',
        port: '3689',
        pathname: '/login',
        search: '?pairing-guid=0xD726D61018D31EDF',
        searchParams: URLSearchParams { 'pairing-guid' => '0xD726D61018D31EDF' },
        hash: '' },
     headers: 
      { Accept: '*/*',
        'Viewer-Only-Client': '1',
        'Client-DAAP-Version': '3.12',
        'Client-ATV-Sharing-Version': '1.2',
        'Client-iTunes-Sharing-Version': '3.10',
        'User-Agent': 'TVRemote/186 CFNetwork/808.1.4 Darwin/16.1.0' },

nt: 
      Agent {
        domain: null,
        _events: [Object],
        _eventsCount: 1,
        _maxListeners: undefined,
        defaultPort: 80,
        protocol: 'http:',
        options: [Object],
        requests: {},
        sockets: [Object],
        freeSockets: {},
        keepAliveMsecs: 1000,
        keepAlive: true,
        maxSockets: 1,
        maxFreeSockets: 1 } } }
[2018-2-18 16:29:16] [DACP] 
[2018-2-18 16:29:16] [DACP] Attempting to reconnect to Apple TV in 0.4 seconds.
grover commented 6 years ago

I assume you're running homebridge in a container as the others? What happens if you ping living.local inside the container/in a terminal on the system that's running homebridge?

quacktacular commented 6 years ago

That's the issue! I can't believe I didn't think to check that.

I looked into it more and it seems like the Alpine OS does not support search domains (like local). Ugh. I had only tried to ping the IP before (which works fine as you can see below). 

/homebridge # ping Living.local
ping: bad address 'Living.local'
/homebridge # ping 10.0.1.3
PING 10.0.1.3 (10.0.1.3): 56 data bytes
64 bytes from 10.0.1.3: seq=0 ttl=64 time=3.016 ms

https://github.com/gliderlabs/docker-alpine/blob/master/docs/caveats.md

Would it be possible to have an optional setting for manual IP? If not I could probably just roll my own Ubuntu container to avoid the issue.

grover commented 6 years ago

Ha! We're getting closer - at least for Alpine Linux. The name resolution of .local domains is not run through regular DNS, but rather through Avahi with the help of nsswitch.conf. Alpine however doesn't have this facility and the configuration file was removed there. As such Alpine will never be able to resolve .local domains at all.

I guess I'll have to include an IP option to resolve the Apple TV and hope that the DACP port doesn't change randomly.

Thanks @quacktacular, this is clearer now.

grover commented 6 years ago

Just to add: The proper solution would be to enable resolution of .local domains through Avahi inside the container, but I can't help with that as I have no experience with Alpine.

grover commented 6 years ago

I've just pushed another update with some changes from @oznu - specifically the use-referer feature was added. @quacktacular could you enable that in your config.json and try again? I'm a bit curious as @oznu also reported pairing issues that you didn't seem to have.

quacktacular commented 6 years ago

Hey @grover I only had a couple minutes to test this morning, but it looks like the control portion is working. Only tried the modified play plays control in Home so far.

I did not try to re-pair (using a pairing code generated from the mDNS version) this morning, but I did last night. It didn’t work with Bomjour. Asked for my pairing code onscreen the Apple TV and got stuck there.

Can try more after work.

AntoGi commented 6 years ago

Hey @grover Thx very much for trying to get a fix here. Highly appreciate it. Any ETA if you're going to push 0.8 also up to NPM? Would make it a bit easier to update HomeBridge on the Synology... If too much trouble, never mind.. will try to install it manually as well and report back asap.. thx!

grover commented 6 years ago

It's not a question of trouble, but rather: Does the version already do what it should do? As such there's only one remaining issue and that's getting feedback if this is working.

Apparently the bonjour stuff does help a bit, but breaks the pairing... :(

grover commented 6 years ago

If someone could try to pair again with the latest version and capture a tcpdump of all udp and tcp traffic in their docker container, that would help me tremendously to figure out the pairing problem with bonjour.

quacktacular commented 6 years ago

@grover confirmed the pairing issue is still present. Here's a tcpdump during the pairing request. Lots of garbage from other services though haha (they are running on other machines). 

tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on docker0, link-type EN10MB (Ethernet), capture size 262144 bytes
17:45:20.735101 IP 172.17.0.7.40376 > 172.17.255.255.21028: UDP, length 335
17:45:23.661207 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 165
17:45:23.887430 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 197
17:45:24.760175 IP 172.17.0.6.9000 > 172.17.0.1.36544: Flags [.], ack 2218030938, win 237, options [nop,nop,TS val 251072905 ecr 543328446], length 0
17:45:24.760239 IP 172.17.0.1.36544 > 172.17.0.6.9000: Flags [.], ack 1, win 502, options [nop,nop,TS val 543508670 ecr 165278260], length 0
17:45:24.760248 IP 172.17.0.6.9000 > 172.17.0.1.34386: Flags [.], ack 3901500255, win 237, options [nop,nop,TS val 251072905 ecr 543328446], length 0
17:45:24.760253 IP 172.17.0.1.34386 > 172.17.0.6.9000: Flags [.], ack 1, win 1444, options [nop,nop,TS val 543508670 ecr 165278260], length 0
17:45:24.760257 IP 172.17.0.6.9000 > 172.17.0.1.38468: Flags [.], ack 1074640020, win 237, options [nop,nop,TS val 251072905 ecr 543328446], length 0
17:45:24.760272 IP 172.17.0.1.38468 > 172.17.0.6.9000: Flags [.], ack 1, win 393, options [nop,nop,TS val 543508670 ecr 165278260], length 0
17:45:24.760276 IP 172.17.0.6.9000 > 172.17.0.1.49364: Flags [.], ack 715626401, win 237, options [nop,nop,TS val 251060688 ecr 543316229], length 0
17:45:28.818573 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 165
17:45:28.856011 ARP, Request who-has 172.17.0.1 tell 172.17.0.5, length 28
17:45:28.856030 ARP, Reply 172.17.0.1 is-at 02:42:e6:7a:d7:89 (oui Unknown), length 28
17:45:29.043915 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 197
17:45:29.880109 ARP, Request who-has 172.17.0.6 tell 172.17.0.1, length 28
17:45:29.880243 ARP, Request who-has 172.17.0.1 tell 172.17.0.6, length 28
17:45:29.880256 ARP, Reply 172.17.0.1 is-at 02:42:e6:7a:d7:89 (oui Unknown), length 28
17:45:29.880259 ARP, Reply 172.17.0.6 is-at 02:42:ac:11:00:02 (oui Unknown), length 28
17:45:34.719807 IP 172.17.0.7.22020 > 77.72.169.210.3478: UDP, length 44
17:45:34.822001 IP 172.17.0.7.22020 > 77.72.169.210.3478: UDP, length 44
17:45:34.876159 IP 77.72.169.210.3478 > 172.17.0.7.22020: UDP, length 56
17:45:34.977890 IP 77.72.169.210.3478 > 172.17.0.7.22020: UDP, length 56
17:45:38.071260 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 69
17:45:39.296124 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 69
17:45:39.826822 IP 172.17.0.7.45624 > espresso.somedomain.net.49511: Flags [P.], seq 923093481:923093510, ack 3680403766, win 24576, length 29
17:45:39.843965 IP espresso.somedomain.net.49511 > 172.17.0.7.45624: Flags [.], ack 29, win 856, length 0
17:45:39.864531 ARP, Request who-has 172.17.0.1 tell 172.17.0.7, length 28
17:45:39.864563 ARP, Reply 172.17.0.1 is-at 02:42:e6:7a:d7:89 (oui Unknown), length 28
17:45:40.124156 ARP, Request who-has 172.17.0.7 tell 172.17.0.1, length 28
17:45:40.124437 ARP, Reply 172.17.0.7 is-at 02:42:ac:11:00:07 (oui Unknown), length 28
17:45:40.890315 IP 172.17.0.7.50712 > S0106b88d125b2dcd.vc.blagh.net.22000: Flags [P.], seq 658721566:658721595, ack 268932247, win 18508, options [nop,nop,TS val 309447799 ecr 2105287221], length 29
17:45:40.919008 IP S0106b88d125b2dcd.vc.blagh.net.22000 > 172.17.0.7.50712: Flags [.], ack 29, win 32767, options [nop,nop,TS val 2105328834 ecr 309447799], length 0
17:45:41.193596 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 117
17:45:41.199457 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 117
17:45:41.365187 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 101
17:45:41.479593 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 165
17:45:41.483460 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 101
17:45:41.656652 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 101
17:45:41.809726 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 165
17:45:41.823014 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 101
17:45:41.824109 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 101
17:45:46.263957 ARP, Request who-has 172.17.0.5 tell 172.17.0.1, length 28
17:45:46.264509 ARP, Reply 172.17.0.5 is-at 02:42:ac:11:00:05 (oui Unknown), length 28
17:45:47.944451 IP syncthing.colintaylor.tech.443 > 172.17.0.7.45216: Flags [P.], seq 2409384327:2409384368, ack 3000950274, win 490, options [nop,nop,TS val 3503815760 ecr 210864341], length 41
17:45:47.947571 IP 172.17.0.7.45216 > syncthing.colintaylor.tech.443: Flags [P.], seq 1:42, ack 41, win 253, options [nop,nop,TS val 210924342 ecr 3503815760], length 41
17:45:48.011103 IP syncthing.colintaylor.tech.443 > 172.17.0.7.45216: Flags [.], ack 42, win 490, options [nop,nop,TS val 3503815826 ecr 210924342], length 0
17:45:50.735800 IP 172.17.0.7.40376 > 172.17.255.255.21028: UDP, length 335
17:45:51.140313 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 69
17:45:51.277351 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 69
17:45:58.881372 IP 172.17.0.7.22020 > 77.72.169.210.3478: UDP, length 44
17:45:58.987925 IP 172.17.0.7.22020 > 77.72.169.210.3478: UDP, length 44
17:45:59.037938 IP 77.72.169.210.3478 > 172.17.0.7.22020: UDP, length 56
17:45:59.145096 IP 77.72.169.210.3478 > 172.17.0.7.22020: UDP, length 56
17:46:01.330143 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 69
17:46:01.335461 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 69
17:46:02.376874 IP 172.17.0.7.41805 > google-public-dns-a.google.com.53: 31838+ AAAA? discovery-v6.syncthing.net. (44)
17:46:02.377883 IP 172.17.0.7.38813 > google-public-dns-a.google.com.53: 60835+ A? discovery-v6.syncthing.net. (44)
17:46:02.405062 IP google-public-dns-a.google.com.53 > 172.17.0.7.38813: 60835 0/1/0 (108)
17:46:02.409920 IP google-public-dns-a.google.com.53 > 172.17.0.7.41805: 31838 2/0/0 AAAA 2001:bc8:4700:2000::515, AAAA 2001:bc8:4400:2200::c39 (100)
17:46:03.504432 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 165
17:46:11.363930 IP 46.166.138.147.1198 > 172.17.0.5.43934: UDP, length 69
17:46:13.472278 IP 172.17.0.5.43934 > 46.166.138.147.1198: UDP, length 69
17:46:13.912143 IP 172.17.0.6.9000 > 172.17.0.1.42396: Flags [.], ack 784783575, win 237, options [nop,nop,TS val 251122057 ecr 543377598], length 0
17:46:13.912218 IP 172.17.0.6.9000 > 172.17.0.1.41502: Flags [.], ack 1563994147, win 237, options [nop,nop,TS val 251122057 ecr 543377598], length 0
17:46:13.912428 IP 172.17.0.1.41502 > 172.17.0.6.9000: Flags [.], ack 1, win 237, options [nop,nop,TS val 543557823 ecr 184787267], length 0
17:46:13.912435 IP 172.17.0.6.9000 > 172.17.0.1.41712: Flags [.], ack 4148534688, win 237, options [nop,nop,TS val 251122057 ecr 543377598], length 0
17:46:13.912449 IP 172.17.0.1.42396 > 172.17.0.6.9000: Flags [.], ack 1, win 1444, options [nop,nop,TS val 543557823 ecr 250573404], length 0
17:46:13.912450 IP 172.17.0.1.41712 > 172.17.0.6.9000: Flags [.], ack 1, win 237, options [nop,nop,TS val 543557823 ecr 184787267], length 0
17:46:13.912455 IP 172.17.0.6.9000 > 172.17.0.1.41534: Flags [.], ack 1357819971, win 237, options [nop,nop,TS val 251122057 ecr 543377598], length 0
17:46:16.472194 ARP, Request who-has 172.17.0.5 tell 172.17.0.1, length 28
17:46:16.473053 ARP, Reply 172.17.0.5 is-at 02:42:ac:11:00:05 (oui Unknown), length 28
^C
71 packets captured
77 packets received by filter
6 packets dropped by kernel
oznu commented 6 years ago

Hi @grover,

If you can't get Bonjour working correctly without to much effort, then perhaps this solution will work (based on your master branch before you swapped to use bonjour):

https://github.com/oznu/homebridge-dacp/commit/ed998cd670707e24cf8587096d8cf64ee366895a

quacktacular commented 6 years ago

@grover @oznu the build above is working perfectly so far :)

grover commented 6 years ago

@oznu Nice! There's just too many MDNS implementations for JS. Let me ponder over this a bit as I really wanted to get rid of the mdns library in the first place. Installing it takes ages on the lower end raspberry pis.

grover commented 6 years ago

I've applied the branch @oznu gave in a slightly different manner adding IPv6 support for those few that are IPv6 only.

This keeps the MDNS library around for now, but I'll plan to get rid of it in a release or two.

If you could verify it again?

oznu commented 6 years ago

Works for me.

grover commented 6 years ago

Also pairing? If so, then I'll release this version.

oznu commented 6 years ago

Pairing works for me as well. Nice work!

AntoGi commented 6 years ago

Hi Thnx all for putting in all your efforts and skills. Pairing works for me now as well.. which is great. However in the Home App on iOS the Remote appears as "Not supported". Can't do anything with it.