Attachment 1453527 Details for Bug 1590371 – TRACE log from connection attempt

TRACE log from connection attempt

nmcli.log (text/plain), 11.60 KB, created by Matthew Woehlke on 2018-06-21 15:05:17 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Matthew Woehlke

Created: 2018-06-21 15:05:17 UTC

Size: 11.60 KB

patch

obsolete

>-- Logs begin at Mon 2018-06-04 13:01:01 EDT, end at Thu 2018-06-21 10:56:37 EDT. --
>Jun 21 10:56:22 goshawk.raptornet.local NetworkManager[23640]: <info>  [1529592982.6243] manager: logging: level 'TRACE' domains 'PLATFORM,RFKILL,ETHER,WIFI,BT,MB,DHCP4,DHCP6,PPP,IP4,IP6,AUTOIP4,DNS,VPN,SHARING,SUPPLICANT,AGENTS,SETTINGS,SUSPEND,CORE,DEVICE,OLPC,INFINIBAND,FIREWALL,ADSL,BOND,VLAN,BRIDGE,TEAM,CONCHECK,DCB,DISPATCH,AUDIT,SYSTEMD,PROXY'
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6771] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: requesting permissions
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6772] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent registered
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6772] policy: re-enabling autoconnect for all connections (only clear no-secrets flag)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <trace> [1529592988.6783] active-connection[0x558cc4c002d0]: creating
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6783] active-connection[0x558cc4c002d0]: set device "enp58s0f1" [0x558cc4b7ece0]
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6783] device[0x558cc4b7ece0] (enp58s0f1): add_pending_action (1): 'activation-0x558cc4c002d0'
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6787] active-connection[0x558cc4c002d0]: constructed (NMVpnConnection, version-id 11, type managed)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <trace> [1529592988.6790] exported-object[0x558cc4c002d0]: export: "/org/freedesktop/NetworkManager/ActiveConnection/10"
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6792] active-connection[0x558cc4c002d0]: set state activating (was unknown)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6793] active-connection[0x558cc4c002d0]: check-master-ready: not signalling (state activating, no master)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <info>  [1529592988.6794] audit: op="connection-activate" uuid="<uuid-redacted>" name="<name-redacted>" pid=31097 uid=0 result="success"
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <info>  [1529592988.6833] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: Started the VPN service, PID 31106
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <info>  [1529592988.6897] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: Saw the service appear; activating connection
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6898] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: requesting VPN secrets pass #1
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6902] Secrets requested for connection /org/freedesktop/NetworkManager/Settings/4 (<name-redacted>/vpn)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6903] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x558cc4c04b40) secrets requested flags 0x80000004 hints '(none)'
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6906] agent-manager: ([0x558cc4c04b40/"<name-redacted>"/"vpn"]) system settings secrets sufficient
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6910] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f57900056d0) existing secrets returned
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6910] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f57900056d0) secrets request completed
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6921] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f57900056d0) new agent secrets processed
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6924] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: asking service if additional secrets are required
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6964] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: service indicated additional secrets required
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6964] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: requesting VPN secrets pass #2
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6968] Secrets requested for connection /org/freedesktop/NetworkManager/Settings/4 (<name-redacted>/vpn)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6969] agent-manager: req[0x558cc4bd68d0, :1.53/org.kde.plasma.networkmanagement/1000]: agent ignored for secrets request [0x7f578c0070a0/"<name-redacted>"/"vpn"] (uid 1000 not required 0)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6969] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent allowed for secrets request [0x7f578c0070a0/"<name-redacted>"/"vpn"]
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6969] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f578c0070a0) secrets requested flags 0x4 hints '(none)'
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6972] agent-manager: ([0x7f578c0070a0/"<name-redacted>"/"vpn"]) system settings secrets insufficient, asking agents
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6973] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent getting secrets for request [0x7f578c0070a0/"<name-redacted>"/"vpn"]
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6973] agent-manager: ([0x7f578c0070a0/"<name-redacted>"/"vpn"]) request has system secrets; checking agent :1.1406 for MODIFY
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6973] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent [0x7f578c0070a0/"<name-redacted>"/"vpn"] MODIFY check result YES
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6989] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent failed secrets request [0x7f578c0070a0/"<name-redacted>"/"vpn"]: Stored passwords not supported
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6989] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x558cc4b5d320) secrets request error: No agents were available for this request.
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.6991] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: asking service if additional secrets are required
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7016] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: service indicated additional secrets required
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7016] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: requesting VPN secrets pass #3
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7021] Secrets requested for connection /org/freedesktop/NetworkManager/Settings/4 (<name-redacted>/vpn)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7022] agent-manager: req[0x558cc4bd68d0, :1.53/org.kde.plasma.networkmanagement/1000]: agent ignored for secrets request [0x7f578c0070a0/"<name-redacted>"/"vpn"] (uid 1000 not required 0)
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7022] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent allowed for secrets request [0x7f578c0070a0/"<name-redacted>"/"vpn"]
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7022] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f578c0070a0) secrets requested flags 0x5 hints '(none)'
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7026] agent-manager: ([0x7f578c0070a0/"<name-redacted>"/"vpn"]) system settings secrets insufficient, asking agents
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7027] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent getting secrets for request [0x7f578c0070a0/"<name-redacted>"/"vpn"]
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7028] agent-manager: ([0x7f578c0070a0/"<name-redacted>"/"vpn"]) request has system secrets; checking agent :1.1406 for MODIFY
>Jun 21 10:56:28 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592988.7028] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent [0x7f578c0070a0/"<name-redacted>"/"vpn"] MODIFY check result YES
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6755] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent returned secrets for request [0x7f578c0070a0/"<name-redacted>"/"vpn"]
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6770] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f5790005680) secrets returned from agent :1.1406
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6771] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f5790005680) secrets request completed
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6801] settings-connection[0x558cc4aa4360,<uuid-redacted>]: (vpn:0x7f5790005680) new agent secrets processed
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6819] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: asking service if additional secrets are required
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <error> [1529592993.6911] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: final secrets request failed to provide sufficient secrets
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6912] active-connection[0x558cc4c002d0]: set state deactivated (was activating)
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6917] active-connection[0x558cc4c002d0]: check-master-ready: not signalling (state deactivated, no master)
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.6917] device[0x558cc4b7ece0] (enp58s0f1): remove_pending_action (0): 'activation-0x558cc4c002d0'
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <info>  [1529592993.6956] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: VPN plugin: state changed: stopped (6)
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <info>  [1529592993.6982] vpn-connection[0x558cc4c002d0,<uuid-redacted>,"<name-redacted>",0]: VPN service disappeared
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.7006] agent-manager: req[0x7f578c0040e0, :1.1406/nmcli-connect/0]: agent unregistered or disappeared
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <trace> [1529592993.7014] exported-object[0x558cc4c002d0]: unexport: "/org/freedesktop/NetworkManager/ActiveConnection/10"
>Jun 21 10:56:33 goshawk.raptornet.local NetworkManager[23640]: <debug> [1529592993.7021] active-connection[0x558cc4c002d0]: disposing

Actions: View

Attachments on bug 1590371: 1453527