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.

Sign up for GitHub

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

Jump to bottom

netmuxd-zeroconf unknown heartbeat error after a while #10

Open
Centterm opened this issue May 18, 2022 · 15 comments
Open

netmuxd-zeroconf unknown heartbeat error after a while #10

Centterm opened this issue May 18, 2022 · 15 comments

Comments

@Centterm
Copy link

Hello,

the old mdns discovery did not work at all for me so I extracted the netmuxd-zeroconf from the current docker container. This version works in the beginning quite well but after a while (hours) AltServer can not find the device anymore. The output of netmuxd is full of unknown heartbeat errors. It never recovers from there and after a restart everything works again.

Adding device 2edff                                                                                                                                                                                 
[2022-05-18T05:12:12Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid 2edff: UnknownError                                                                                      
Removing 2edff                                                                                                                                                                                      
Adding device 2edff                                                                                                                                                                                 
[2022-05-18T05:12:27Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid 2edff: UnknownError                                                                                      
Removing 2edff                                                                                                                                                                                      
Adding device 2edff                                                                                                                                                                                 
[2022-05-18T05:13:15Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid 2edff: UnknownError                                                                                      
Removing 2edff                                                                                                                                                                                      
Adding device 2edff                                                                                                                                                                                 
[2022-05-18T05:16:02Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid 2edff: UnknownError                                                                                      
Removing 2edff                                                                                                                                                                                      
Adding device 2edff                                                                                                                                                                                 
[2022-05-18T05:19:30Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid 2edff: UnknownError                                                                                      
Removing 2edff

(UUID shorted for readability)

I do not know if that is the intended behavior but I do also get a lot of adding/removing the device when it works
@Practicalbutterfly5
Copy link

Practicalbutterfly5 commented May 30, 2022 •
edited
Loading

I am also facing same issue.
This is the error

netmuxd/src/heartbeat.rs

Line 27 in 1275069

"Failed to create heartbeat client for udid {}: {:?}",

@DrissiReda
Copy link

DrissiReda commented Jul 3, 2022 •
edited
Loading

I am also facing this issue.

I can see it in AltServer-Linux. It works fine with usbmuxd. But when I set the env var USBMUXD_SOCKET_ADDRESS to switch to netmuxd, I start getting the same error:

Adding device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:26:21Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid xxxxxxxx-xxxxxxxxx: UnknownError
Adding device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:26:31Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid xxxxxxxx-xxxxxxxxx: UnknownError
Adding device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:26:41Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid xxxxxxxx-xxxxxxxxx: UnknownError

Then it keeps repeating every 10 seconds.

@jkcoxson
Copy link
Owner

jkcoxson commented Jul 3, 2022

Can you run with the env var RUST_LOG=info

@DrissiReda
Copy link 

WARNING: Running in host mode will not work unless you are running a daemon in unix mode as well
[2022-07-03T17:31:32Z INFO  netmuxd::central_data] Getting UDID for MAC: "xx:xx:xx:xx:xx:xx"
[2022-07-03T17:31:32Z INFO  plist_plus] Parsing xml
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 2998967729
[2022-07-03T17:31:32Z INFO  plist_plus::types::dictionary] Getting dict item
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 1256711957
[2022-07-03T17:31:32Z INFO  plist_plus] Cloning plist
[2022-07-03T17:31:32Z INFO  plist_plus] Getting type of cloned plist
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 2938159892
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 1256711957
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  plist_plus::types::string] Getting string value
[2022-07-03T17:31:32Z INFO  plist_plus::types::string] Converting cstring to string
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 2938159892
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 2998967729
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  plist_plus] Parsing xml
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 1168404114
[2022-07-03T17:31:32Z INFO  plist_plus::types::dictionary] Getting dict item
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 2080556298
[2022-07-03T17:31:32Z INFO  plist_plus] Cloning plist
[2022-07-03T17:31:32Z INFO  plist_plus] Getting type of cloned plist
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 1402125424
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 2080556298
[2022-07-03T17:31:32Z WARN  plist_plus] Plist has already been freed
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 1402125424
[2022-07-03T17:31:32Z WARN  plist_plus] Plist has already been freed
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 1168404114
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  plist_plus] Parsing xml
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 1492039906
[2022-07-03T17:31:32Z INFO  plist_plus::types::dictionary] Getting dict item
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 1748401340
[2022-07-03T17:31:32Z INFO  plist_plus] Cloning plist
[2022-07-03T17:31:32Z INFO  plist_plus] Getting type of cloned plist
[2022-07-03T17:31:32Z INFO  plist_plus] Creating plist from plist_t with id 3586890328
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 1748401340
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  plist_plus::types::string] Getting string value
[2022-07-03T17:31:32Z INFO  plist_plus::types::string] Converting cstring to string
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 3586890328
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  plist_plus] Dropping plist 1492039906
[2022-07-03T17:31:32Z INFO  plist_plus] Plist dropped
[2022-07-03T17:31:32Z INFO  netmuxd::central_data] Found UDID: "xxxxxxxx-xxxxxxxxx"
Adding device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:31:32Z INFO  rusty_libimobiledevice::idevice] Converting udid to C string
[2022-07-03T17:31:32Z INFO  rusty_libimobiledevice::idevice] Creating udid ptr
[2022-07-03T17:31:32Z INFO  rusty_libimobiledevice::idevice] Converting ip address into bytes
[2022-07-03T17:31:32Z INFO  rusty_libimobiledevice::idevice] Encodings ipv4 address
[2022-07-03T17:31:32Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid xxxxxxxx-xxxxxxxxx: UnknownError
[2022-07-03T17:31:32Z INFO  rusty_libimobiledevice::idevice] Dropping device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:31:32Z INFO  netmuxd::heartbeat] Removing device xxxxxxxx-xxxxxxxxx from muxer
[2022-07-03T17:31:32Z INFO  netmuxd::central_data] Removing device: "xxxxxxxx-xxxxxxxxx"

Can you run with the env var RUST_LOG=info

@jkcoxson

@jkcoxson
Copy link
Owner

jkcoxson commented Jul 3, 2022

This looks like an error with an invalid pairing file. I would try regenerating it with usbmuxd.

Also, you seem to be running an outdated build, or it’s using outdated deps.

@DrissiReda
Copy link

DrissiReda commented Jul 3, 2022 •
edited
Loading

This looks like an error with an invalid pairing file. I would try regenerating it with usbmuxd.

Also, you seem to be running an outdated build, or it’s using outdated deps.

I'm pulling them from debian, maybe that's why? I just generated the pairing file.

Tell me which dependencies might be causing an issue I'll try building them manually since debian has old versions.

@DrissiReda
Copy link

@jkcoxson

After unpairing/repairing I'm getting this:

WARNING: Running in host mode will not work unless you are running a daemon in unix mode as well
[2022-07-03T17:42:20Z INFO  netmuxd::central_data] Getting UDID for MAC: "xx:xx:xx:xx:xx"
[2022-07-03T17:42:20Z INFO  plist_plus] Parsing xml
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 2553729807
[2022-07-03T17:42:20Z INFO  plist_plus::types::dictionary] Getting dict item
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 3353063795
[2022-07-03T17:42:20Z INFO  plist_plus] Cloning plist
[2022-07-03T17:42:20Z INFO  plist_plus] Getting type of cloned plist
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 2708026803
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 3353063795
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  plist_plus::types::string] Getting string value
[2022-07-03T17:42:20Z INFO  plist_plus::types::string] Converting cstring to string
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 2708026803
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 2553729807
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  plist_plus] Parsing xml
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 3451195937
[2022-07-03T17:42:20Z INFO  plist_plus::types::dictionary] Getting dict item
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 2269541282
[2022-07-03T17:42:20Z INFO  plist_plus] Cloning plist
[2022-07-03T17:42:20Z INFO  plist_plus] Getting type of cloned plist
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 3065494590
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 2269541282
[2022-07-03T17:42:20Z WARN  plist_plus] Plist has already been freed
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 3065494590
[2022-07-03T17:42:20Z WARN  plist_plus] Plist has already been freed
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 3451195937
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  plist_plus] Parsing xml
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 3988722464
[2022-07-03T17:42:20Z INFO  plist_plus::types::dictionary] Getting dict item
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 1099965478
[2022-07-03T17:42:20Z INFO  plist_plus] Cloning plist
[2022-07-03T17:42:20Z INFO  plist_plus] Getting type of cloned plist
[2022-07-03T17:42:20Z INFO  plist_plus] Creating plist from plist_t with id 359847415
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 1099965478
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  plist_plus::types::string] Getting string value
[2022-07-03T17:42:20Z INFO  plist_plus::types::string] Converting cstring to string
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 359847415
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  plist_plus] Dropping plist 3988722464
[2022-07-03T17:42:20Z INFO  plist_plus] Plist dropped
[2022-07-03T17:42:20Z INFO  netmuxd::central_data] Found UDID: "xxxxxxxx-xxxxxxxxx"
Adding device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:42:20Z INFO  rusty_libimobiledevice::idevice] Converting udid to C string
[2022-07-03T17:42:20Z INFO  rusty_libimobiledevice::idevice] Creating udid ptr
[2022-07-03T17:42:20Z INFO  rusty_libimobiledevice::idevice] Converting ip address into bytes
[2022-07-03T17:42:20Z INFO  rusty_libimobiledevice::idevice] Encodings ipv4 address
[2022-07-03T17:42:20Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid xxxxxxxx-xxxxxxxxx: UnknownError
[2022-07-03T17:42:20Z INFO  rusty_libimobiledevice::idevice] Dropping device xxxxxxxx-xxxxxxxxx
[2022-07-03T17:42:20Z INFO  netmuxd::heartbeat] Removing device xxxxxxxx-xxxxxxxxx from muxer
[2022-07-03T17:42:20Z INFO  netmuxd::central_data] Removing device: "xxxxxxxx-xxxxxxxxx"

@jkcoxson
Copy link
Owner

jkcoxson commented Jul 6, 2022

Please try the latest build that was just pushed. Post logs with RUST_LOG=info.

@jkcoxson jkcoxson mentioned this issue Jul 15, 2022
Closed
@Demuos
Copy link

Demuos commented Jul 22, 2022 •
edited
Loading

I compiled from source. Still got a Hearthbeat failure after a while.

full log:
https://gist.github.com/Demuos/a04d0c5a3878697064d5fb387448d366

@Staubgeborener
Copy link

Staubgeborener commented Jul 31, 2022 •
edited
Loading

I have the same problem @jkcoxson, here is my netmuxd logfile: https://gist.github.com/Staubgeborener/fdcb8d88060c59daea25e2666c048592

There seems to be also a difference by running netmuxd as root or not:

[user@nuc ~]$ sudo netmuxd disable-unix host 127.0.0.1
Starting netmuxd
Starting mDNS discovery
Listening on /var/run/usbmuxd
Adding device UUID-OF-MY-IPHONE


[user@nuc ~]$ netmuxd disable-unix host 127.0.0.1
Starting netmuxd
Starting mDNS discovery
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 98, kind: AddrInUse, message: "Address already in use" }', src/main.rs:151:75
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

The Adding device UUID-OF-MY-IPHONE appears when i enter export USBMUXD_SOCKET_ADDRESS=127.0.0.1:27015 in a different tab. idevice_id can list my iPhone over USB-Cable, but without USB-Cable (only wifi), i'll get ERROR: Unable to retrieve device list! - but netmuxd seems to recognize my iPhone as i get the Adding device UUID-OF-MY-IPHONE after setting the env variable USBMUXD_SOCKET_ADDRESS. More informations can be found here.
What is the correct way to pair the device with usbmuxd? I only did idevicepair pair so far which creates a /var/lib/lockdown/UUID-OF-MY-IPHONE.plist file.

I also tried the netmuxd-zeroconf file from the latest docker build like

docker pull ghcr.io/jkcoxson/netmuxd:latest
docker run ghcr.io/jkcoxson/netmuxd
docker cp 21b258146c14:/usr/local/bin/netmuxd-zeroconf /usr/local/bin/netmuxd-zeroconf

which runs into

[user@nuc ~]$ sudo ./netmuxd-zeroconf 
Starting netmuxd
Listening on /var/run/usbmuxd
iDevice plugged in!
iDevice plugged in!
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Busy', src/usb.rs:47:18
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Serial number: serialnumberstring
Starting mDNS discovery for _apple-mobdev2._tcp.local with zeroconf
Adding device UUID-OF-IPHONE


# Starting AltServer and Press "Refresh All" in Altstore on iPhone
Failed to handle request:There was an error connecting to the device.

[user@nuc ~]$ sudo ./netmuxd-zeroconf --disable-unix --host 127.0.0.1
Starting netmuxd
Listening on 127.0.0.1:27015
WARNING: Running in host mode will not work unless you are running a daemon in unix mode as well
Starting mDNS discovery for _apple-mobdev2._tcp.local with zeroconf
Adding device UUID-OF-IPHONE
[2022-07-31T09:03:14Z ERROR netmuxd::heartbeat] Failed to create heartbeat client for udid UUID-OF-IPHONE: UnknownError
Removing UUID-OF-IPHONE


# Starting AltServer and Press "Refresh All" in Altstore on iPhone
Failed to handle request:AltServer could not find the device.

Btw i already re-paired the iPhone several times like

sudo rm /var/lib/lockdown/UUID-OF-IPHONE.plist
idevicepair pair
SUCCESS: Paired with device UUID-OF-IPHONE

@Staubgeborener Staubgeborener mentioned this issue Jul 31, 2022
Closed
@Practicalbutterfly5
Copy link

Practicalbutterfly5 commented Aug 1, 2022 •
edited
Loading

@Staubgeborener I was in the same boat as you, was getting the heartbeat issue. For now, I am able to solve it. Here are all steps I did. You can try step 0 first and see if that solves the issue, if not try all the steps.

EDIT: Step 0: Restart wifi on ios

  1. sudo systemctl restart avahi-daemon
  2. sudo killall -s SIGKILL altserver usbmuxd netmuxd
  3. Start usbmuxd(sudo usbmuxd) altserver(sudo altserver) and connect device via usb
  4. Refresh one app, it should go successfully.
  5. sudo kill -9 $(pidof usbmuxd)
  6. Make sure usbmuxd is not running (ps -A | grep usbmuxd)
  7. Start netmuxd(sudo netmuxd). Note that --disable-unix flag and host parameter was not included.
  8. Start altserver without the environment variable(sudo altserver)

@Staubgeborener
Copy link

@Practicalbutterfly5 I can confirm, that this is working. The most important step is sudo kill -9 $(pidof usbmuxd). Only using sudo systemctl stop usbmuxd is not enough. In my case, the steps to get rid of this issue:

  1. Start usbmuxd(sudo usbmuxd) and connect device via usb
  2. idevicepair pair
  3. check deviceinfo with ideviceinfo
  4. sudo kill -9 $(pidof usbmuxd) (check the pid with ps -a | grep usbmuxd)
  5. sudo ./netmuxd (in my case i dont need the -host 127.0.0.1:27015 argument)
  6. open a new tab in terminal and start ./AltServer

@Demuos
Copy link

Demuos commented Aug 4, 2022 •
edited
Loading

I´m not using AltServer with netmuxd, but with the libmobiledevice Library the Heartbeat error after a while ist still present. The described Solution indeed helped, when netmuxd doesn`t want to start at all. @Staubgeborener Are there no more Heartbeat failures in your netmuxd log?

[2022-08-04T08:37:57Z INFO  netmuxd::devices] Getting UDID for MAC: "xxx"
[2022-08-04T08:37:57Z INFO  netmuxd::devices] Found UDID: "00008030-xxx"
[2022-08-04T08:37:57Z INFO  netmuxd::mdns] Device has already been added to muxer, skipping
[2022-08-04T08:37:59Z INFO  netmuxd::heartbeat] Heartbeat failed for 00008030-xxx
[2022-08-04T08:37:59Z INFO  rusty_libimobiledevice::services::heartbeat] Dropping heartbeat client
Removing 00008030-xxx
[2022-08-04T08:37:59Z INFO  rusty_libimobiledevice::idevice] Dropping device 00008030-xxx
[2022-08-04T08:37:59Z INFO  netmuxd::devices] Removing device: "00008030-xxx"

Netmuxd keeps Adding and Removing the Device all the time. Which makes automatic headless iphone backup to my Ubuntu NAS not possible.

Adding device 00008030-xxx
Removing 00008030-xxx
Adding device 00008030-xxx
Removing 00008030-xxx
Adding device 00008030-xxx
Removing 00008030-xxx

I already tried a cron Script that waits for the Adding Device output and then start backup, but even then I often get No Device found and it only works in 10% of the cases.

@Staubgeborener
Copy link

@Demuos No, i don't have any errors. Netmuxd runs the last 3 days without issues. I'll get the adding device message when i unlock my iPhone and the removing message when my device is locked. So i don't really care about it as i use this only for AltServer. And in this case, my iPhone is always unlocked. I can't tell you where the problem really is on your side, but like i said, killing the usbmuxd process sudo kill -9 $(pidof usbmuxd) was my solution.

@Demuos
Copy link

Demuos commented Aug 9, 2022

I found a problem with my startscript, which tried to start netmuxd more than once. Netmuxd and automated backups are working fine for 2 days now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@DrissiReda @jkcoxson @Staubgeborener @Centterm @Practicalbutterfly5 @Demuos