Bug 1176319 - [abrt] NetworkManager: nm_device_activate_stage3_ip4_start(): NetworkManager killed by SIGABRT
Summary: [abrt] NetworkManager: nm_device_activate_stage3_ip4_start(): NetworkManager ...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 21
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Lubomir Rintel
QA Contact: Fedora Extras Quality Assurance
URL: https://retrace.fedoraproject.org/faf...
Whiteboard: abrt_hash:10f2f4b552735407738993f4b92...
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-12-20 12:48 UTC by autarch princeps
Modified: 2015-05-08 21:37 UTC (History)
5 users (show)

Fixed In Version: network-manager-applet-0.9.10.2-1.fc21
Clone Of:
Environment:
Last Closed: 2015-03-21 04:56:54 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: backtrace (29.49 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: cgroup (208 bytes, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: core_backtrace (12.25 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: dso_list (7.80 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: environ (72 bytes, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: limits (1.29 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: maps (34.34 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: open_fds (2.70 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: proc_pid_status (907 bytes, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details
File: var_log_messages (21.20 KB, text/plain)
2014-12-20 12:49 UTC, autarch princeps
no flags Details

Description autarch princeps 2014-12-20 12:48:57 UTC
Version-Release number of selected component:
NetworkManager-0.9.10.0-14.git20140704.fc21

Additional info:
reporter:       libreport-2.3.0
backtrace_rating: 4
cmdline:        /usr/sbin/NetworkManager --no-daemon
crash_function: nm_device_activate_stage3_ip4_start
executable:     /usr/sbin/NetworkManager
kernel:         3.17.7-300.fc21.x86_64
runlevel:       N 5
type:           CCpp
uid:            0

Truncated backtrace:
Thread no. 1 (2 frames)
 #4 nm_device_activate_stage3_ip4_start at devices/nm-device.c:3951
 #5 nm_device_activate_stage3_ip_config_start at devices/nm-device.c:4067

Comment 1 autarch princeps 2014-12-20 12:49:01 UTC
Created attachment 971439 [details]
File: backtrace

Comment 2 autarch princeps 2014-12-20 12:49:03 UTC
Created attachment 971440 [details]
File: cgroup

Comment 3 autarch princeps 2014-12-20 12:49:04 UTC
Created attachment 971441 [details]
File: core_backtrace

Comment 4 autarch princeps 2014-12-20 12:49:06 UTC
Created attachment 971442 [details]
File: dso_list

Comment 5 autarch princeps 2014-12-20 12:49:07 UTC
Created attachment 971443 [details]
File: environ

Comment 6 autarch princeps 2014-12-20 12:49:09 UTC
Created attachment 971444 [details]
File: limits

Comment 7 autarch princeps 2014-12-20 12:49:11 UTC
Created attachment 971445 [details]
File: maps

Comment 8 autarch princeps 2014-12-20 12:49:12 UTC
Created attachment 971446 [details]
File: open_fds

Comment 9 autarch princeps 2014-12-20 12:49:14 UTC
Created attachment 971447 [details]
File: proc_pid_status

Comment 10 autarch princeps 2014-12-20 12:49:16 UTC
Created attachment 971448 [details]
File: var_log_messages

Comment 11 Lubomir Rintel 2015-01-07 10:56:43 UTC
Seems like a recurring issue.

I'm wondering if you can be a bit more specific about the configuration that caused this to happen?

Comment 12 Tomáš Hozza 2015-03-01 10:23:12 UTC
This happened also to me.

I have virbr interfaces created by libvirt, on which I have dnsmasq running. I just added the Ethernet port to the bridge, so I can reuse the libvirt's dnsmasq instance (# brctl addif virbr0 em1). After connecting Raspberry Pi using ethernet cable to the em1 interface, NM crashed.

(gdb) bt
#0  0x00007fd2319a58c7 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:55
#1  0x00007fd2319a752a in __GI_abort () at abort.c:89
#2  0x00007fd2321ba9b5 in g_assertion_message (domain=domain@entry=0x7fd235cdb841 "NetworkManager", file=file@entry=0x7fd235cc9c42 "devices/nm-device.c", line=line@entry=4049, func=func@entry=0x7fd235ccedc0 <__FUNCTION__.38128> "nm_device_activate_stage3_ip4_start", message=message@entry=0x7fd2376301c0 "assertion failed: (priv->ip4_state == IP_WAIT)") at gtestutils.c:2291
#3  0x00007fd2321baa4a in g_assertion_message_expr (domain=domain@entry=0x7fd235cdb841 "NetworkManager", file=file@entry=0x7fd235cc9c42 "devices/nm-device.c", line=line@entry=4049, func=func@entry=0x7fd235ccedc0 <__FUNCTION__.38128> "nm_device_activate_stage3_ip4_start", expr=expr@entry=0x7fd235ccaec9 "priv->ip4_state == IP_WAIT")
    at gtestutils.c:2306
#4  0x00007fd235c448ac in nm_device_activate_stage3_ip4_start (self=self@entry=0x7fd2375fe3d0 [NMDeviceEthernet]) at devices/nm-device.c:4049
#5  0x00007fd235c45068 in nm_device_activate_stage3_ip_config_start (user_data=<optimized out>) at devices/nm-device.c:4204
#6  0x00007fd232194aeb in g_main_context_dispatch (context=0x7fd237546d00) at gmain.c:3111
#7  0x00007fd232194aeb in g_main_context_dispatch (context=context@entry=0x7fd237546d00) at gmain.c:3710
#8  0x00007fd232194e88 in g_main_context_iterate (context=0x7fd237546d00, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3781
#9  0x00007fd2321951b2 in g_main_loop_run (loop=0x7fd237546a60) at gmain.c:3975
#10 0x00007fd235c320fe in main (argc=1, argv=0x7fff39985928) at main.c:686


# rpm -q NetworkManager
NetworkManager-0.9.10.1-3.20150219git.fc21.x86_64

Comment 13 Tomáš Hozza 2015-03-01 10:26:16 UTC
Mar 01 11:14:25 thozza-pc NetworkManager[887]: <info>  (virbr0): bridge port em1 was attached
Mar 01 11:14:25 thozza-pc NetworkManager[887]: <info>  (em1): enslaved to virbr0
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  (em1): link connected
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  (em1): device state change: unavailable -> disconnected (reason 'carrier-changed') [20 30 40]
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Auto-activating connection 'em1'.
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) starting connection 'em1'
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 1 of 5 (Device Prepare) scheduled...
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 1 of 5 (Device Prepare) started...
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  (em1): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) scheduled...
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 1 of 5 (Device Prepare) complete.
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) starting...
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  (em1): device state change: prepare -> config (reason 'none') [40 50 0]
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) successful.
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 2 of 5 (Device Configure) complete.
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 3 of 5 (IP Configure Start) scheduled.
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  Activation (em1) Stage 3 of 5 (IP Configure Start) started...
Mar 01 11:14:37 thozza-pc NetworkManager[887]: <info>  (em1): device state change: config -> ip-config (reason 'none') [50 70 0]
Mar 01 11:14:37 thozza-pc NetworkManager[887]: **
Mar 01 11:14:37 thozza-pc NetworkManager[887]: NetworkManager:ERROR:devices/nm-device.c:4049:nm_device_activate_stage3_ip4_start: assertion failed: (priv->ip4_state == IP_WAIT)
Mar 01 11:14:37 thozza-pc systemd[1]: NetworkManager.service: main process exited, code=dumped, status=6/ABRT
Mar 01 11:14:37 thozza-pc systemd[1]: Unit NetworkManager.service entered failed state.
Mar 01 11:14:37 thozza-pc systemd[1]: NetworkManager.service failed.

Comment 14 Dan Williams 2015-03-02 21:57:23 UTC
This is wierd, I cannot reproduce the situation above with nm-0-9-10 git.  I created an auto-connect connection for my p4p1, ensured p4p1 didn't have a carrier, then 'brctl addif virbr0 p4p1', then plugged in the cable.  NM does proceed to activate the interface (which is a mistake, since it's a slave of course) but I don't get a crash.

Could you grab some earlier log output from NM when it crashes here?

Comment 15 Dan Williams 2015-03-02 22:25:37 UTC
Reproducer:

1) ensure virbr0 has an IP address
2) ensure eth0 doesn't have a carrier
3) ensure ignore-carrier is not set
4) ensure there's an autoconnect connection for eth0
5) run NetworkManager, it will pick up and assume virbr0
6) plug cable into eth0

Ok, the culprit is nm_device_slave_notify_enslave() being called during activation of the auto-connect connection in stage2, because the device is a slave of the bridge.  But in reality NM shouldn't be auto-activating the connection at all, since it's not compatible with the device's current state (which is a slave).

Comment 16 Dan Williams 2015-03-02 22:30:38 UTC
NM 1.0+ doesn't have this problem because it creates a slave connection for the device whenever it's a slave, and assumes that, while 0.9.10 doesn't do that.

Comment 17 Tomáš Hozza 2015-03-03 08:02:36 UTC
The issue was not easily reproducible on my system. It happened only once so I was able to provide at least description of what I did. Also logs are lost since I don't use persistent journal.

Anyway thank you Dan for finding the cause.

Comment 18 Dan Williams 2015-03-03 22:16:47 UTC
Upstream branch fixing this issue is http://cgit.freedesktop.org/NetworkManager/NetworkManager/log/?h=dcbw/nm-0-9-10-slaves

Comment 19 Fedora Update System 2015-03-04 17:25:38 UTC
NetworkManager-0.9.10.2-1.fc21,network-manager-applet-0.9.10.2-1.fc21 has been submitted as an update for Fedora 21.
https://admin.fedoraproject.org/updates/NetworkManager-0.9.10.2-1.fc21,network-manager-applet-0.9.10.2-1.fc21

Comment 20 Fedora Update System 2015-03-05 12:39:23 UTC
Package network-manager-applet-0.9.10.2-1.fc21, NetworkManager-0.9.10.2-1.fc21:
* should fix your issue,
* was pushed to the Fedora 21 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing network-manager-applet-0.9.10.2-1.fc21 NetworkManager-0.9.10.2-1.fc21'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2015-3238/NetworkManager-0.9.10.2-1.fc21,network-manager-applet-0.9.10.2-1.fc21
then log in and leave karma (feedback).

Comment 21 Fedora Update System 2015-03-21 04:56:54 UTC
network-manager-applet-0.9.10.2-1.fc21, NetworkManager-0.9.10.2-1.fc21 has been pushed to the Fedora 21 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.