Bug#816384: systemd: Systemd tries to rename ppp interface when .link files present for existing NICs

Vladimir Kudrya pzs-fs at yandex.ru
Tue Mar 1 12:45:01 GMT 2016


Package: systemd
Version: 228-6
Severity: important

Dear Maintainer, when .link files are in place in /etc/systemd/network to rename
NICs based on MAC addresses, systemd tries to rename ppp0 link which is being
created by NetworkManager. This results in failure to establish PPTP connection.

$ cat /etc/systemd/network/10-eth0.link
[Match]
MACAddress="xx:xx:xx:xx:xx:xx"
[Link]
Name=eth0

$ cat /etc/systemd/network/10-wlan0.link
[Match]
MACAddress="yy:yy:yy:yy:yy:yy"
[Link]
Name=wlan0

Nothing here can possibly be related to any ppp iface. But here is the journal
while trying to establish PPTP via NetworkManager. "ppp0" is being renamed to "rename13"
when these files are in place. It does not happen when they are not.

Mar 01 15:26:22 hostname NetworkManager[797]: <info>  op="connection-activate" uuid="16be4658-71fd-4027-aa6d-ce3e2de2a189" name="pptp-connection-profile" pid=4763 uid=1000 result="success"
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: Started the VPN service, PID 4770
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: Saw the service appear; activating connection
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN plugin: state changed: init (1)
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN connection: (ConnectInteractive) reply received
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN plugin: state changed: starting (3)
Mar 01 15:26:22 hostname NetworkManager[797]: ** Message: pppd started with pid 4776
Mar 01 15:26:22 hostname pppd[4776]: Plugin /usr/lib/pppd/2.4.7/nm-pptp-pppd-plugin.so loaded.
Mar 01 15:26:22 hostname NetworkManager[797]: Plugin /usr/lib/pppd/2.4.7/nm-pptp-pppd-plugin.so loaded.
Mar 01 15:26:22 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (plugin_init): initializing
Mar 01 15:26:22 hostname pppd[4776]: pppd 2.4.7 started by root, uid 0
Mar 01 15:26:22 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
Mar 01 15:26:22 hostname dbus[722]: [system] Rejected send message, 8 matched rules; type="method_return", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.60855" (uid=0 pid=4776 comm="/usr/sbin/pppd pty /usr/sbin/pptp [pptp_gateway_address] -")
Mar 01 15:26:22 hostname pppd[4776]: Using interface ppp0
Mar 01 15:26:22 hostname pppd[4776]: Connect: ppp0 <--> /dev/pts/4
Mar 01 15:26:22 hostname NetworkManager[797]: Using interface ppp0
Mar 01 15:26:22 hostname NetworkManager[797]: Connect: ppp0 <--> /dev/pts/4
Mar 01 15:26:22 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  (ppp0): new Generic device (/org/freedesktop/NetworkManager/Devices/12)
Mar 01 15:26:22 hostname dbus[722]: [system] Rejected send message, 8 matched rules; type="method_return", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.60855" (uid=0 pid=4776 comm="/usr/sbin/pppd pty /usr/sbin/pptp [pptp_gateway_address] -")
Mar 01 15:26:22 hostname pptp[4781]: nm-pptp-service-4770 log[main:pptp.c:350]: The synchronous pptp option is NOT activated
Mar 01 15:26:22 hostname kernel: rename13: renamed from ppp0
Mar 01 15:26:22 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_rep:pptp_ctrl.c:259]: Sent control packet type is 1 'Start-Control-Connection-Request'
Mar 01 15:26:22 hostname NetworkManager[797]: <info>  (ppp0): interface index 13 renamed iface from 'ppp0' to 'rename13'
Mar 01 15:26:22 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_disp:pptp_ctrl.c:781]: Received Start Control Connection Reply
Mar 01 15:26:22 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_disp:pptp_ctrl.c:815]: Client connection established.
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_rep:pptp_ctrl.c:259]: Sent control packet type is 7 'Outgoing-Call-Request'
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_disp:pptp_ctrl.c:900]: Received Outgoing Call Reply.
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_disp:pptp_ctrl.c:939]: Outgoing call established (call ID 41039, peer's call ID 28160).
Mar 01 15:26:23 hostname pppd[4776]: ioctl(SIOCSIFMTU): No such device (line 1220)
Mar 01 15:26:23 hostname NetworkManager[797]: ioctl(SIOCSIFMTU): No such device (line 1220)
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (get_credentials): passwd-hook, requesting credentials...
Mar 01 15:26:23 hostname dbus[722]: [system] Rejected send message, 8 matched rules; type="method_return", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.60855" (uid=0 pid=4776 comm="/usr/sbin/pppd pty /usr/sbin/pptp [pptp_gateway_address] -")
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (get_credentials): got credentials from NetworkManager-pptp
Mar 01 15:26:23 hostname pppd[4776]: CHAP authentication succeeded
Mar 01 15:26:23 hostname NetworkManager[797]: CHAP authentication succeeded
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
Mar 01 15:26:23 hostname dbus[722]: [system] Rejected send message, 8 matched rules; type="method_return", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.60855" (uid=0 pid=4776 comm="/usr/sbin/pppd pty /usr/sbin/pptp [pptp_gateway_address] -")
Mar 01 15:26:23 hostname pppd[4776]: ioctl(SIOCGIFMTU): No such device (line 1235)
Mar 01 15:26:23 hostname NetworkManager[797]: ioctl(SIOCGIFMTU): No such device (line 1235)
Mar 01 15:26:23 hostname pppd[4776]: LCP terminated by peer (MPPE required but peer refused)
Mar 01 15:26:23 hostname NetworkManager[797]: LCP terminated by peer (MPPE required but peer refused)
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
Mar 01 15:26:23 hostname dbus[722]: [system] Rejected send message, 8 matched rules; type="method_return", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.60855" (uid=0 pid=4776 comm="/usr/sbin/pppd pty /usr/sbin/pptp [pptp_gateway_address] -")
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[pptp_read_some:pptp_ctrl.c:586]: read returned zero, peer has closed
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[callmgr_main:pptp_callmgr.c:269]: Closing connection (shutdown)
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[ctrlp_rep:pptp_ctrl.c:259]: Sent control packet type is 12 'Call-Clear-Request'
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[pptp_read_some:pptp_ctrl.c:586]: read returned zero, peer has closed
Mar 01 15:26:23 hostname pptp[4791]: nm-pptp-service-4770 log[call_callback:pptp_callmgr.c:84]: Closing connection (call state)
Mar 01 15:26:23 hostname pppd[4776]: Modem hangup
Mar 01 15:26:23 hostname pppd[4776]: Connection terminated.
Mar 01 15:26:23 hostname NetworkManager[797]: Modem hangup
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Mar 01 15:26:23 hostname NetworkManager[797]: Connection terminated.
Mar 01 15:26:23 hostname dbus[722]: [system] Rejected send message, 8 matched rules; type="method_return", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.60855" (uid=0 pid=4776 comm="/usr/sbin/pppd pty /usr/sbin/pptp [pptp_gateway_address] -")
Mar 01 15:26:23 hostname NetworkManager[797]: <error> [1456835183.813006] [platform/nm-linux-platform.c:3847] do_change_link(): platform-linux: do-change-link[13]: failure changing link: failure 19 (No such device)
Mar 01 15:26:23 hostname NetworkManager[797]: <warn>  (rename13): failed to disable userspace IPv6LL address handling
Mar 01 15:26:23 hostname NetworkManager[797]: <warn>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN plugin: failed: connect-failed (1)
Mar 01 15:26:23 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN plugin: state changed: stopping (5)
Mar 01 15:26:23 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN plugin: state changed: stopped (6)
Mar 01 15:26:23 hostname dbus[722]: [system] Rejected send message, 9 matched rules; type="error", sender=":1.60854" (uid=0 pid=4770 comm="/usr/lib/NetworkManager/nm-pptp-service ") interface="(unset)" member="(unset)" error name="org.freedesktop.NetworkManager.VPN.Error.AlreadyStopped" requested_reply="0" destination=":1.5" (uid=0 pid=797 comm="/usr/sbin/NetworkManager --no-daemon ")
Mar 01 15:26:23 hostname NetworkManager[797]: <info>  vpn-connection[0x19f2490,16be4658-71fd-4027-aa6d-ce3e2de2a189,"pptp-connection-profile",0]: VPN plugin: state change reason: unknown (0)
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: Terminated ppp daemon with PID 4776.
Mar 01 15:26:23 hostname org.freedesktop.Notifications[20991]: Could not load icon: 'gnome-lockscreen'
Mar 01 15:26:23 hostname org.freedesktop.Notifications[20991]: Could not load icon: 'gnome-lockscreen'
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
Mar 01 15:26:23 hostname pppd[4776]: Exit.
Mar 01 15:26:23 hostname NetworkManager[797]: ** Message: nm-pptp-ppp-plugin: (nm_exit_notify): cleaning up
Mar 01 15:26:23 hostname NetworkManager[797]: ** (nm-pptp-service:4770): WARNING **: pppd exited with error code 16
Mar 01 15:26:23 hostname systemd-udevd[4780]: error changing net interface name 'ppp0' to 'eth0': No such device
Mar 01 15:26:23 hostname systemd-udevd[4780]: could not rename interface '13' from 'ppp0' to 'eth0': No such device
Mar 01 15:26:23 hostname NetworkManager[797]: <info>  devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Mar 01 15:26:23 hostname NetworkManager[797]: <info>  device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
Mar 01 15:26:23 hostname NetworkManager[797]: <info>  devices removed (path: /sys/devices/virtual/net/rename13, iface: rename13)



-- Package-specific info:

-- System Information:
Debian Release: stretch/sid
  APT prefers testing
  APT policy: (900, 'testing'), (400, 'unstable'), (300, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.4.0-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=ru_RU.UTF-8, LC_CTYPE=ru_RU.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages systemd depends on:
ii  adduser         3.113+nmu3
ii  libacl1         2.2.52-3
ii  libapparmor1    2.10-3
ii  libaudit1       1:2.4.5-1
ii  libblkid1       2.27.1-3
ii  libc6           2.21-9
ii  libcap2         1:2.24-12
ii  libcap2-bin     1:2.24-12
ii  libcryptsetup4  2:1.7.0-2
ii  libgcrypt20     1.6.5-2
ii  libkmod2        22-1
ii  liblzma5        5.1.1alpha+20120614-2.1
ii  libmount1       2.27.1-3
ii  libpam0g        1.1.8-3.2
ii  libseccomp2     2.2.3-3
ii  libselinux1     2.4-3
ii  libsystemd0     228-6
ii  mount           2.27.1-3
ii  util-linux      2.27.1-3

Versions of packages systemd recommends:
ii  dbus            1.10.6-1
ii  libpam-systemd  228-6

Versions of packages systemd suggests:
pn  systemd-container  <none>
pn  systemd-ui         <none>

Versions of packages systemd is related to:
ii  udev  228-6

-- Configuration Files:
/etc/systemd/journald.conf changed:
[Journal]
Storage=persistent
SystemMaxUse=256M


-- no debconf information



More information about the Pkg-systemd-maintainers mailing list