2

I have a very nasty issue with Jessie :-(

Background: I wrote a tool called raspiBackup which backups and restores a Raspberry and because it works fine for me and helped me multiple times to recover from a SD card failure I decided to publish it. It's already used by a lot of people.

Issue: When I restore the clone/backup of Wheezy created with tar the system comes up with an IP address.

When I restore the clone/backup Jessie created with tar the system doesn't receive an IP from my local dhcp server. If I start the original image everything works fine.

When I restore the clone/backup Jessie created with rsync the system works fine.

Backup options used with rsync: -rlptgoDWDEHAXx

Backup options used with tar: -cp --selinux --acls --xattrs

I also compared the two logs /var/log/syslog from the original Jessie system saved with tar and the restored Jessie system which doesn't get an IP.

Original image:

Jun 22 19:10:58 jessie-small avahi-daemon[336]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::93ca:50ee:da9d:3d04.
Jun 22 19:10:58 jessie-small kernel: [   14.543974] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Jun 22 19:10:58 jessie-small kernel: [   14.549440] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jun 22 19:10:58 jessie-small avahi-daemon[336]: New relevant interface eth0.IPv6 for mDNS.
Jun 22 19:10:58 jessie-small avahi-daemon[336]: Registering new address record for fe80::93ca:50ee:da9d:3d04 on eth0.*.
Jun 22 19:10:58 jessie-small dhcpcd[331]: eth0: waiting for carrier
Jun 22 19:10:59 jessie-small kernel: [   16.252955] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
Jun 22 19:10:59 jessie-small kernel: [   16.257045] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Jun 22 19:10:59 jessie-small dhcpcd[331]: eth0: carrier acquired
Jun 22 19:10:59 jessie-small dhcpcd[331]: DUID 00:01:00:01:20:7e:13:d4:b8:27:eb:f7:28:f5
Jun 22 19:10:59 jessie-small dhcpcd[331]: eth0: IAID eb:b4:e8:74
Jun 22 19:11:00 jessie-small dhcpcd[331]: eth0: soliciting an IPv6 router
Jun 22 19:11:00 jessie-small dhcpcd[331]: eth0: rebinding lease of 192.168.0.100
Jun 22 19:11:01 jessie-small kernel: [   18.250280] random: nonblocking pool is initialized
Jun 22 19:11:05 jessie-small dhcpcd[331]: eth0: leased 192.168.0.100 for 864000 seconds
Jun 22 19:11:06 jessie-small dhcpcd[331]: eth0: adding route to 192.168.0.0/24
Jun 22 19:11:06 jessie-small dhcpcd[331]: eth0: adding default route via 192.168.0.1
Jun 22 19:11:06 jessie-small avahi-daemon[336]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.100.
Jun 22 19:11:06 jessie-small avahi-daemon[336]: New relevant interface eth0.IPv4 for mDNS.
Jun 22 19:11:06 jessie-small avahi-daemon[336]: Registering new address record for 192.168.0.100 on eth0.IPv4.
Jun 22 19:11:06 jessie-small dhcpcd[331]: forked to background, child pid 542
Jun 22 19:11:06 jessie-small systemd[1]: Started dhcpcd on all interfaces.
Jun 22 19:11:06 jessie-small systemd[1]: Starting Network.

Cloned image:

Jun 22 19:10:25 jessie-small avahi-daemon[336]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::e41d:db7e:7264:fadb.
Jun 22 19:10:25 jessie-small kernel: [   16.584421] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Jun 22 19:10:25 jessie-small kernel: [   16.590118] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Jun 22 19:10:25 jessie-small avahi-daemon[336]: New relevant interface eth0.IPv6 for mDNS.
Jun 22 19:10:25 jessie-small avahi-daemon[336]: Registering new address record for fe80::e41d:db7e:7264:fadb on eth0.*.
Jun 22 19:10:25 jessie-small dhcpcd[335]: eth0: waiting for carrier
Jun 22 19:10:25 jessie-small systemd[1]: dhcpcd.service: control process exited, code=killed status=11
Jun 22 19:10:25 jessie-small systemd[1]: Failed to start dhcpcd on all interfaces.
Jun 22 19:10:25 jessie-small systemd[1]: Unit dhcpcd.service entered failed state.
Jun 22 19:10:25 jessie-small systemd[1]: Starting Network.

Command executed on cloned Jessie:

systemctl status -l dhcpcd.service
● dhcpcd.service - dhcpcd on all interfaces
   Loaded: loaded (/lib/systemd/system/dhcpcd.service; enabled)
  Drop-In: /etc/systemd/system/dhcpcd.service.d
           └─wait.conf
   Active: failed (Result: signal) since Thu 2017-06-22 22:13:35 CEST; 1min 58s ago
  Process: 334 ExecStart=/sbin/dhcpcd -q -w (code=killed, signal=SEGV)

Jun 22 22:13:32 jessie-small dhcpcd[334]: version 6.7.1 starting
Jun 22 22:13:33 jessie-small dhcpcd[334]: eth0: adding address fe80::e41d:db7e:7264:fadb
Jun 22 22:13:35 jessie-small systemd[1]: dhcpcd.service: control process exited, code=killed status=11
Jun 22 22:13:35 jessie-small systemd[1]: Failed to start dhcpcd on all interfaces.
Jun 22 22:13:35 jessie-small systemd[1]: Unit dhcpcd.service entered failed state.

Warning: Unit file changed on disk, 'systemctl daemon-reload' recommended.

I found out you can fix the dhcp issue on the cloned image by starting the dhcp server manually to get an IP from the local DHCP server and then uninstall and install the dhcp client again with

sudo dhcpcd eth0
sudo apt-get remove dhcpcd5
sudo apt-get install dhcpcd5

Unfortunately you need console access and a connected monitor which is very inconvenient because raspiBackup is used most of the time on headless systems.

Another solution is to use networkd on Jessie.

It seems somehow be related to systemd which is new in Jessie and the different way a backup is created with tar and rsync.

Does somebody have an idea what's the root cause for the issue? My goal is to have the restored Jessie image to start again like the original image with an IP without any workarounds.

Update 6/25

I started two Raspis - the original and the clone image, enabled debug on dhcp and extracted all dhcp messages from /var/log/syslog.

I noticed

Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: udev: starting
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: dev: loaded udev

is missing in the clone image. Looks like the interface is not started :-(

Jun 23 20:33:15 jessie-small dhcpcd[351]: version 6.7.1 starting
Jun 23 20:33:15 jessie-small dhcpcd[351]: eth0: disabling kernel IPv6 RA support
Jun 23 20:33:15 jessie-small dhcpcd[351]: eth0: adding address fe80::e41d:db7e:7264:fadb
Jun 23 20:33:15 jessie-small dhcpcd[351]: eth0: pltime infinity, vltime infinity
Jun 23 20:33:15 jessie-small dhcpcd[351]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
Jun 23 20:33:15 jessie-small dhcpcd[351]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
Jun 23 20:33:17 jessie-small dhcpcd[351]: eth0: waiting for carrier
Jun 23 20:33:17 jessie-small systemd[1]: dhcpcd.service: control process exited, code=killed status=11
Jun 23 20:33:17 jessie-small systemd[1]: Failed to start dhcpcd on all interfaces.
Jun 23 20:33:17 jessie-small systemd[1]: Unit dhcpcd.service entered failed state.
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: version 6.7.1 starting
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: udev: starting
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: dev: loaded udev
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: eth0: disabling kernel IPv6 RA support
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: eth0: adding address fe80::e41d:db7e:7264:fadb
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: eth0: pltime infinity, vltime infinity
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
Jun 25 16:49:20 jessie-small-06 dhcpcd[357]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
Jun 25 16:49:21 jessie-small-06 dhcpcd[357]: eth0: waiting for carrier
Jun 25 16:49:21 jessie-small-06 dhcpcd[357]: eth0: carrier acquired
Jun 25 16:49:21 jessie-small-06 dhcpcd[357]: eth0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
Jun 25 16:49:21 jessie-small-06 dhcpcd[357]: DUID 00:01:00:01:20:dc:fd:c0:b8:27:eb:d6:a6:c9
Jun 25 16:49:21 jessie-small-06 dhcpcd[357]: eth0: IAID eb:d6:a6:c9
Jun 25 16:49:21 jessie-small-06 dhcpcd[357]: eth0: delaying IPv6 router solicitation for 0.2 seconds

Update 7/13: This is an important issue for me. That's why I posted the same question in this forum and consider that post as the primary post for my issue from now on.

0

Did you make sure that there aren't any dhcpcd lease files getting cloned? While DHCPv4 identifies clients by MAC48, a cloned lease file may cause problems with some DHCP servers. For reference, my FritzBox differentiates identically cloned RPis by their digferent MAC48s, but on DHCPv6 you get strange results due to the cloned DUID that is independent of the leases.

  • I see. That's another difference between Wheezy and Jessy I didn't know about: dhcpv4 vs dhcpv6. I executed 'sudo rm /var/lib/dhcpcd5/dhcpcd*.lease' and rebootet the system but it didn't get an IP :-( – framp Jun 22 '17 at 19:04
  • I've only now noticed in your log file for the cloned image that the dhcpcd service fails. What does sudo systemctl status -l dhcpcd.service report? This should show the output of the dhcpcd service (unit). – TheDiveO Jun 22 '17 at 19:59
  • I also missed that you are cross-cloning between Wheezy and Jessie ... don't! This will never work, because Wheezy is init-based, Jesie is systemd-based. Also, dhcpcd in Wheezy is 4.x, in Jessie it's 6.x wroth lots of differences, you should notice from the different places for configuration files, et cetera ... dhcpcd versus dhcpcd5. – TheDiveO Jun 22 '17 at 20:01
  • I added the output in my question above. – framp Jun 22 '17 at 20:22
  • Not sure I get what you mean by crosscloning. I have one raspi1 up and running with Jessie, cloned this one to another SD card, put this SD card into another raspi1 and booted the clone. There is no Wheezy in charge. I mentioned Wheezy because I don't have this issue with Wheezy. It's just an issue with Jessie :-( – framp Jun 22 '17 at 20:23

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.