Bug 895253 - [abrt] NetworkManager-0.9.7.0-12.git20121004.fc18: activation_failure_handler: Process /usr/sbin/NetworkManager was killed by signal 6 (SIGABRT)
Summary: [abrt] NetworkManager-0.9.7.0-12.git20121004.fc18: activation_failure_handler...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 18
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:f1ca0ee1829e7631bc9ff216ad6...
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-01-14 22:46 UTC by Moez Roy
Modified: 2014-02-05 14:50 UTC (History)
3 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2014-02-05 14:50:52 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: backtrace (31.48 KB, text/plain)
2013-01-14 22:46 UTC, Moez Roy
no flags Details
File: cgroup (174 bytes, text/plain)
2013-01-14 22:46 UTC, Moez Roy
no flags Details
File: core_backtrace (5.67 KB, text/plain)
2013-01-14 22:46 UTC, Moez Roy
no flags Details
File: dso_list (4.26 KB, text/plain)
2013-01-14 22:46 UTC, Moez Roy
no flags Details
File: environ (123 bytes, text/plain)
2013-01-14 22:46 UTC, Moez Roy
no flags Details
File: limits (1.29 KB, text/plain)
2013-01-14 22:47 UTC, Moez Roy
no flags Details
File: maps (20.83 KB, text/plain)
2013-01-14 22:47 UTC, Moez Roy
no flags Details
File: open_fds (702 bytes, text/plain)
2013-01-14 22:47 UTC, Moez Roy
no flags Details
File: proc_pid_status (889 bytes, text/plain)
2013-01-14 22:47 UTC, Moez Roy
no flags Details
File: var_log_messages (10.96 KB, text/plain)
2013-01-14 22:47 UTC, Moez Roy
no flags Details

Description Moez Roy 2013-01-14 22:46:38 UTC
Version-Release number of selected component:
NetworkManager-0.9.7.0-12.git20121004.fc18

Additional info:
backtrace_rating: 4
cmdline:        /usr/sbin/NetworkManager --no-daemon
crash_function: activation_failure_handler
executable:     /usr/sbin/NetworkManager
kernel:         3.7.1-5.fc18.x86_64
remote_result:  NOTFOUND
uid:            0

Truncated backtrace:
Thread no. 1 (10 frames)
 #4 activation_failure_handler at nm-device-wifi.c:3331
 #5 device_state_changed at nm-device-wifi.c:3463
 #9 g_signal_emit_by_name at gsignal.c:3393
 #10 nm_device_state_changed at nm-device.c:4644
 #15 connection_vpn_state_changed at nm-vpn-manager.c:131
 #20 nm_vpn_connection_set_vpn_state at nm-vpn-connection.c:229
 #24 g_signal_emit_by_name at gsignal.c:3393
 #25 nm_device_state_changed at nm-device.c:4644
 #26 internal_activate_device at nm-manager.c:2274
 #27 nm_manager_activate_connection at nm-manager.c:2766

Comment 1 Moez Roy 2013-01-14 22:46:43 UTC
Created attachment 678470 [details]
File: backtrace

Comment 2 Moez Roy 2013-01-14 22:46:47 UTC
Created attachment 678471 [details]
File: cgroup

Comment 3 Moez Roy 2013-01-14 22:46:50 UTC
Created attachment 678472 [details]
File: core_backtrace

Comment 4 Moez Roy 2013-01-14 22:46:53 UTC
Created attachment 678473 [details]
File: dso_list

Comment 5 Moez Roy 2013-01-14 22:46:58 UTC
Created attachment 678474 [details]
File: environ

Comment 6 Moez Roy 2013-01-14 22:47:01 UTC
Created attachment 678475 [details]
File: limits

Comment 7 Moez Roy 2013-01-14 22:47:07 UTC
Created attachment 678476 [details]
File: maps

Comment 8 Moez Roy 2013-01-14 22:47:09 UTC
Created attachment 678477 [details]
File: open_fds

Comment 9 Moez Roy 2013-01-14 22:47:12 UTC
Created attachment 678478 [details]
File: proc_pid_status

Comment 10 Moez Roy 2013-01-14 22:47:16 UTC
Created attachment 678479 [details]
File: var_log_messages

Comment 11 Dan Williams 2013-03-11 15:34:51 UTC
Relevant bits are:

Jan 14 12:37:32 localhost NetworkManager[896]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) complete.
Jan 14 12:37:32 localhost NetworkManager[896]: <info> VPN service 'openvpn' appeared; activating connections
Jan 14 12:37:32 localhost NetworkManager[896]: <info> VPN plugin state changed: starting (3)
Jan 14 12:37:32 localhost NetworkManager[896]: <info> VPN connection 'openvpn-Swe' (Connect) reply received.
Jan 14 14:37:42 localhost NetworkManager[896]: <info> (wlan0): disconnecting for new activation request.
Jan 14 14:37:42 localhost NetworkManager[896]: <info> (wlan0): device state change: secondaries -> disconnected (reason 'none') [90 30 0]
Jan 14 14:37:42 localhost NetworkManager[896]: <info> (wlan0): deactivating device (reason 'none') [0]
Jan 14 14:37:42 localhost NetworkManager[896]: <info> (wlan0): canceled DHCP transaction, DHCP client pid 2898
Jan 14 14:37:42 localhost NetworkManager[896]: <info> (wlan0): device state change: disconnected -> failed (reason 'secondary-connection-failed') [30 120 54]
Jan 14 14:37:42 localhost abrt[2918]: Saved core dump of pid 896 (/usr/sbin/NetworkManager) to /var/spool/abrt/ccpp-2013-01-14-14:37:42-896 (27418624 bytes)

static void
activation_failure_handler (NMDevice *dev)
{
	NMDeviceWifi *self = NM_DEVICE_WIFI (dev);
	NMAccessPoint *ap;
	NMConnection *connection;

	connection = nm_device_get_connection (dev);
>>>>	g_assert (connection);


The "new activation request" is what kills things here, because when the new request comes in, internal_activate_device() calls:

nm_device_state_changed (device,
                         NM_DEVICE_STATE_DISCONNECTED,
                         NM_DEVICE_STATE_REASON_NONE);

which then ends up calling nm_device_deactivate(), which clears out the activating request and thus the device's NMConnection.  That's why the assertion triggers.  But the real bug is why the Wifi device is even getting to this code, given that the device should already be disconnected and the wifi code shouldn't be handling this as a failure.

So after being deactivated, the VPN connection is listening to the device's state changes, and that ends up in device_state_changed() in nm-vpn-connection.c.  Since the underlying device is being disconnected, the VPN disconnects itself with nm_vpn_connection_set_vpn_state(NM_VPN_CONNECTION_STATE_DISCONNECTED).  That triggers connection_vpn_state_changed() in nm-vpn-manager.c, which listens to VPN disconnection signals.  That re-emits the signal as CONNECTION_DEACTIVATED, which is picked up by nm-policy.c's vpn_connection_deactivated() which calls process_secondaries(), which then calls:

nm_device_state_changed (item_device, NM_DEVICE_STATE_FAILED, NM_DEVICE_STATE_REASON_SECONDARY_CONNECTION_FAILED);

because the VPN connection was still activating.  However, the device is already in the DISCONNECTED state by this point, although the signal has not yet been fully processed because the original call to nm_device_state_changed(DISCONNECTED) hasn't exited that function yet.

The easiest fix is probably something like this in process_secondaries():

+	if (nm_device_is_activating (item_device) || nm_device_get_state (item_device) == NM_DEVICE_STATE_ACTIVATED) {
		nm_device_state_changed (item_device, NM_DEVICE_STATE_FAILED,
				NM_DEVICE_STATE_REASON_SECONDARY_CONNECTION_FAILED);
+	}

Comment 12 Dan Williams 2013-03-11 15:37:29 UTC
Either that, or since the VPN connection disconnects itself with the reason code NM_VPN_CONNECTION_STATE_REASON_DEVICE_DISCONNECTED, perhaps process_secondaries() should somehow use that reason code and not change the device's state, since it's already being deactivated.

Comment 13 Fedora End Of Life 2013-12-21 10:22:54 UTC
This message is a reminder that Fedora 18 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 18. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '18'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 18's end of life.

Thank you for reporting this issue and we are sorry that we may not be 
able to fix it before Fedora 18 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior to Fedora 18's end of life.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 14 Fedora End Of Life 2014-02-05 14:50:55 UTC
Fedora 18 changed to end-of-life (EOL) status on 2014-01-14. Fedora 18 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


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