Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
AntoGi opened this issue Jan 2, 2018 · 52 comments
Closed

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

AntoGi opened this issue Jan 2, 2018 · 52 comments
Assignees
Labels

Comments

@AntoGi
Copy link

AntoGi commented Jan 2, 2018

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
Copy link
Owner

grover commented Jan 5, 2018

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
Copy link
Author

AntoGi commented Jan 5, 2018

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
Copy link
Author

AntoGi commented Jan 5, 2018

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
Copy link
Owner

grover commented Jan 5, 2018

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
Copy link
Owner

grover commented Jan 5, 2018

Just found this: agnat/node_mdns#130

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

@grover grover self-assigned this Jan 5, 2018
@grover grover added the bug label Jan 5, 2018
@AntoGi
Copy link
Author

AntoGi commented Jan 6, 2018

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 grover closed this as completed in e6c2b0f Jan 6, 2018
@grover
Copy link
Owner

grover commented Jan 6, 2018

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?

@grover grover reopened this Jan 6, 2018
@AntoGi
Copy link
Author

AntoGi commented Jan 6, 2018

Will do asap.. will let you know!

Thx a million!

@AntoGi
Copy link
Author

AntoGi commented Jan 6, 2018

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
Copy link
Owner

grover commented Jan 6, 2018

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
Copy link
Author

AntoGi commented Jan 6, 2018

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
Copy link
Author

AntoGi commented Jan 6, 2018

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
Copy link
Author

AntoGi commented Jan 6, 2018

Let me know what to do next...

@grover
Copy link
Owner

grover commented Jan 6, 2018 via email

@AntoGi
Copy link
Author

AntoGi commented Jan 6, 2018

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]

@AntoGi AntoGi closed this as completed Jan 6, 2018
@AntoGi AntoGi reopened this Jan 6, 2018
@grover
Copy link
Owner

grover commented Jan 6, 2018

:(

@AntoGi
Copy link
Author

AntoGi commented Jan 6, 2018

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
Copy link
Author

AntoGi commented Jan 6, 2018

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

@AntoGi
Copy link
Author

AntoGi commented Jan 6, 2018

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

@grover
Copy link
Owner

grover commented Jan 7, 2018

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
Copy link
Owner

grover commented Jan 7, 2018

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
Copy link
Author

AntoGi commented Jan 7, 2018

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
Copy link
Author

AntoGi commented Jan 7, 2018

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
Copy link
Author

AntoGi commented Jan 8, 2018

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/

@grover
Copy link
Owner

grover commented Feb 18, 2018

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:

  • uninstalling any previous version you have
  • installing the latest code from github: npm install -g github:grover/homebridge-dacp (You might need sudo)

and running it again? Feedback appreciated.

@quacktacular
Copy link

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
Copy link
Owner

grover commented Feb 18, 2018

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
Copy link

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
Copy link
Owner

grover commented Feb 19, 2018

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

@quacktacular
Copy link

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
Copy link
Owner

grover commented Feb 19, 2018

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
Copy link

quacktacular commented Feb 19, 2018

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
Copy link
Owner

grover commented Feb 19, 2018

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
Copy link
Owner

grover commented Feb 19, 2018

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
Copy link
Owner

grover commented Feb 19, 2018

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
Copy link

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
Copy link
Author

AntoGi commented Feb 19, 2018

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
Copy link
Owner

grover commented Feb 19, 2018

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
Copy link
Owner

grover commented Feb 19, 2018

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
Copy link

@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
Copy link

oznu commented Feb 20, 2018

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

  • It keeps the mdns library in place.
  • Removes the mdns resolver sequence entries that were causing failures when nss_mdns was not enabled.
  • Use a pure javascript implementation to resolve the IP address from the .local domain just before connecting.
  • No need for the use-referer flag since the above library is doing a real mdns dns query and listening for the response (just like nss_mdns would be doing otherwise), so you should be able to safely transition all users onto it.

@quacktacular
Copy link

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

@grover
Copy link
Owner

grover commented Feb 20, 2018

@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
Copy link
Owner

grover commented Feb 20, 2018

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
Copy link

oznu commented Feb 20, 2018

Works for me.

@grover
Copy link
Owner

grover commented Feb 20, 2018

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

@oznu
Copy link

oznu commented Feb 20, 2018

Pairing works for me as well. Nice work!

grover added a commit that referenced this issue Feb 20, 2018
Added support to start preconfigured playlists
Bugfixes for issue #10 (getaddrinfo fails to resolve Bonjour .local addresses)
@AntoGi
Copy link
Author

AntoGi commented Feb 20, 2018

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.

@grover
Copy link
Owner

grover commented Feb 20, 2018

Please see Apps and Features.

@grover grover closed this as completed Feb 20, 2018
@bohtho
Copy link

bohtho commented Apr 11, 2018

@grover I think I have a similar problem with mdns as of today. DACP plugin v0.9.1, Homebridge v0.4.38, node v9.9.0:

[2018-4-11 23:52:35] [DACP] Failed to resolve service Peisestue.local. using IPv4 MDNS lookups.
[2018-4-11 23:52:35] [DACP] Specific error: Error: Could not resolve Peisestue.local - Query Timed Out
at Timeout.setTimeout (/usr/local/lib/node_modules/homebridge-dacp/node_modules/mdns-resolver/src/index.ts:19:14)
at ontimeout (timers.js:466:11)
at tryOnTimeout (timers.js:304:5)
at Timer.listOnTimeout (timers.js:267:5)
[2018-4-11 23:52:36] [DACP] Failed to resolve service Peisestue.local. using IPv4 MDNS lookups.
[2018-4-11 23:52:36] [DACP] Specific error: Error: Could not resolve Peisestue.local - Query Timed Out
at Timeout.setTimeout (/usr/local/lib/node_modules/homebridge-dacp/node_modules/mdns-resolver/src/index.ts:19:14)
at ontimeout (timers.js:466:11)
at tryOnTimeout (timers.js:304:5)
at Timer.listOnTimeout (timers.js:267:5)
[2018-4-11 23:52:38] [DACP] Failed to resolve service Peisestue.local. using IPv4 and IPv6 MDNS lookups.
[2018-4-11 23:52:38] [DACP] Discarding service.
[2018-4-11 23:52:38] [DACP] Specific error: Error: Could not resolve Peisestue.local - Query Timed Out
at Timeout.setTimeout (/usr/local/lib/node_modules/homebridge-dacp/node_modules/mdns-resolver/src/index.ts:19:14)
at ontimeout (timers.js:466:11)
at tryOnTimeout (timers.js:304:5)
at Timer.listOnTimeout (timers.js:267:5)
[2018-4-11 23:52:39] [DACP] Failed to resolve service Peisestue.local. using IPv4 and IPv6 MDNS lookups.
[2018-4-11 23:52:39] [DACP] Discarding service.
[2018-4-11 23:52:39] [DACP] Specific error: Error: Could not resolve Peisestue.local - Query Timed Out
at Timeout.setTimeout (/usr/local/lib/node_modules/homebridge-dacp/node_modules/mdns-resolver/src/index.ts:19:14)
at ontimeout (timers.js:466:11)
at tryOnTimeout (timers.js:304:5)
at Timer.listOnTimeout (timers.js:267:5)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

6 participants