Thank you for your bug report, you would probably have a better chance
to get a reply reporting upstream on
https://gitlab.freedesktop.org/NetworkManager/NetworkManager/issues/

** Changed in: network-manager (Ubuntu)
   Importance: Undecided => Low

-- 
You received this bug notification because you are a member of Desktop
Packages, which is subscribed to network-manager in Ubuntu.
https://bugs.launchpad.net/bugs/1906120

Title:
  NetworkManager: error -111 disaptching events on DHCPv4 lease renewal

Status in network-manager package in Ubuntu:
  New

Bug description:
  Ubuntu 20.04.1 running on armv7 (IFC6410)

  Occasional network interruption with the following message in journal:

  Nov 28 12:03:16 drako NetworkManager[4094]: <trace> [1606582996.3983] 
device[dabf59d236aff82b] (enp1s0): activation-stage: complete 
activate_stage5_ip_config_result_6,v6 (id 51751)
  Nov 28 12:03:16 drako NetworkManager[4094]: <debug> [1606582996.4026] 
device[dabf59d236aff82b] (enp1s0): ip6-config: update (commit=0, 
new-config=0x803e6140)
  Nov 28 12:03:18 drako NetworkManager[4094]: <error> [1606582998.8611] dhcp4 
(enp1s0): error -111 dispatching events
  Nov 28 12:03:18 drako NetworkManager[4094]: <info>  [1606582998.8614] dhcp4 
(enp1s0): state changed extended -> fail
  Nov 28 12:03:18 drako NetworkManager[4094]: <info>  [1606582998.8622] device 
(enp1s0): DHCPv4: trying to acquire a new lease within 90 seconds
  Nov 28 12:04:49 drako NetworkManager[4094]: <info>  [1606583089.4023] device 
(enp1s0): DHCPv4: grace period expired

  the ipv4 connection is then cut (the interface looses ipc4 address and
  the ipv4 routes are purged) until NetworkManager is restarted.

  The networkmanager-dispatcher.service doesn't indicate any error:

  Nov 28 06:04:05 drako systemd[1]: Started Network Manager Script Dispatcher 
Service.
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: new 
request (2 scripts)
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_DBUS_PATH=/org/freedesktop/NetworkManager/Settings/1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_FILENAME=/etc/NetworkManager/system-connections/Wired
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_UUID=fe299e22-2b52-43ff-9a60-fa385e239f41
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_ID=Wired
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DEVICE_IFACE=enp1s0
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DEVICE_IP_IFACE=enp1s0

  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change'
  [enp1s0]: environment: IP4_NUM_ADDRESSES=1

  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change'
  [enp1s0]: environment: IP4_NUM_ROUTES=1

  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: IP6_NUM_ROUTES=3
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_DHCP_LEASE_TIME=28800
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_EXPIRY=1606590245

  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_BROADCAST_ADDRESS=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_DOMAIN_NAME=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_DOMAIN_NAME_SERVERS=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_DOMAIN_SEARCH=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_HOST_NAME=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_INTERFACE_MTU=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_MS_CLASSLESS_STATIC_ROUTES=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_NIS_DOMAIN=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_NIS_SERVERS=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_NTP_SERVERS=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_RFC3442_CLASSLESS_STATIC_ROUTES=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_ROOT_PATH=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_ROUTERS=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_STATIC_ROUTES=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_SUBNET_MASK=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_TIME_OFFSET=1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DHCP4_REQUESTED_WPAD=1

  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: NM_DISPATCHER_ACTION=dhcp4-change
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
start running ordered scripts...
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0], 
"/etc/NetworkManager/dispatcher.d/01-ifupdown": run script
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0], 
"/etc/NetworkManager/dispatcher.d/01-ifupdown": complete
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0], 
"/etc/NetworkManager/dispatcher.d/ntp": run script
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0], 
"/etc/NetworkManager/dispatcher.d/ntp": complete
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
completed (2 scripts)
  Nov 28 06:04:15 drako systemd[1]: NetworkManager-dispatcher.service: 
Succeeded.

  but the last dispatcher log entry is 6 hours before the error.

  The error is doesn't happen all the time. The difference between
  sucesfull DHCP renewal is failure is:

  SUCCESS:

  Nov 28 03:04:05 drako NetworkManager[4094]: <debug> [1606550645.1859] dhcp4 
(enp1s0): send REQUEST of X.X.X.X to Y.Y.Y.Y
  ... REPEATS EVERY 1 MIN ...
  Nov 28 06:03:23 drako NetworkManager[4094]: <debug> [1606561403.3185] dhcp4 
(enp1s0): send REQUEST of X.X.X.X to Y.Y.Y.Y
  Nov 28 06:04:05 drako NetworkManager[4094]: <debug> [1606561445.2416] dhcp4 
(enp1s0): send REQUEST of X.X.X.X to 255.255.255.255
  Nov 28 06:04:05 drako NetworkManager[4094]: <debug> [1606561445.2467] dhcp4 
(enp1s0): received ACK of X.X.X.X from 0.0.0.0
  Nov 28 06:04:05 drako NetworkManager[4094]: <trace> [1606561445.2474] dhcp4 
(enp1s0): client event 4
  Nov 28 06:04:05 drako NetworkManager[4094]: <trace> [1606561445.2476] dhcp4 
(enp1s0): lease available (extended)
  Nov 28 06:04:05 drako NetworkManager[4094]: <info>  [1606561445.2640] dhcp4 
(enp1s0): option dhcp_lease_time      => '28800'
  ...
  SUCCESSFUL LEASE
  ...
  Nov 28 06:04:05 drako NetworkManager[4094]: <info>  [1606561445.2691] dhcp4 
(enp1s0): state changed bound -> extended
  Nov 28 06:04:05 drako NetworkManager[4094]: <debug> [1606561445.2891] 
dispatcher: (6) (enp1s0) dispatching action 'dhcp4-change'
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: new 
request (2 scripts)
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_DBUS_PATH=/org/freedesktop/NetworkManager/Settings/1
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_FILENAME=/etc/NetworkManager/system-connections/Wired
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_UUID=fe299e22-2b52-43ff-9a60-fa385e239f41
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: CONNECTION_ID=Wired
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DEVICE_IFACE=enp1s0
  Nov 28 06:04:05 drako nm-dispatcher[5178]: req:1 'dhcp4-change' [enp1s0]: 
environment: DEVICE_IP_IFACE=enp1s0

  FAILURE:
  Nov 28 10:04:05 drako NetworkManager[4094]: <debug> [1606575845.1875] dhcp4 
(enp1s0): send REQUEST of X.X.X.X to Y.Y.Y.Y
  ... REPEATS EVERY 1 MINUTE ...
  Nov 28 12:02:59 drako NetworkManager[4094]: <debug> [1606582979.0265] dhcp4 
(enp1s0): send REQUEST of X.X.X.X to Y.Y.Y.Y
  Nov 28 12:03:18 drako NetworkManager[4094]: <error> [1606582998.8611] dhcp4 
(enp1s0): error -111 dispatching events
  Nov 28 12:03:18 drako NetworkManager[4094]: <info>  [1606582998.8614] dhcp4 
(enp1s0): state changed extended -> fail

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/network-manager/+bug/1906120/+subscriptions

-- 
Mailing list: https://launchpad.net/~desktop-packages
Post to     : desktop-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~desktop-packages
More help   : https://help.launchpad.net/ListHelp

Reply via email to