[SOLVED] "systemd --user" instance not working, results in login-pr...

koen · 2015-11-11 21:20:18

Hey!

Arch Linux has been working like a charm for me for the last few months, but now I'm running into a problem that I can't fix on my own.

I think that my main problem is that "systemd --user" instance is not starting or running correctly. Concretely, I am getting errors such as

[koen@vesoldo: ~]$ systemctl --user status
Failed to read server status: Input/output error

although in tty1, the error message is

[koen@vesoldo: ~]$ systemctl --user status
ailed to connect to bus: Connection refused

Somehow, this create a lot of trouble in my boot sequence:

[koen@vesoldo: ~]$ journalctl -b | grep systemd
2:Nov 11 13:01:31 vesoldo systemd-journald[143]: Runtime journal (/run/log/journal/) is currently using 8.0M.
6:Nov 11 13:01:31 vesoldo systemd-journald[143]: System journal (/var/log/journal/) is currently using 944.1M.
10:Nov 11 13:01:32 vesoldo systemd-journald[143]: Time spent on flushing to /var is 126.842ms for 2 entries.
563:Nov 11 13:01:32 vesoldo kernel: random: systemd-tmpfile urandom read with 4 bits of entropy available
669:Nov 11 13:01:32 vesoldo systemd[1]: systemd 227 running in system mode. (+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD +IDN)
670:Nov 11 13:01:32 vesoldo systemd[1]: Detected architecture x86-64.
671:Nov 11 13:01:32 vesoldo systemd[1]: Set hostname to <vesoldo>.
673:Nov 11 13:01:32 vesoldo systemd[1]: Listening on Journal Socket.
674:Nov 11 13:01:32 vesoldo systemd[1]: Listening on LVM2 metadata daemon socket.
675:Nov 11 13:01:32 vesoldo systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
676:Nov 11 13:01:32 vesoldo systemd[1]: Reached target Swap.
677:Nov 11 13:01:32 vesoldo systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
678:Nov 11 13:01:32 vesoldo systemd[1]: Listening on Device-mapper event daemon FIFOs.
679:Nov 11 13:01:32 vesoldo systemd[1]: Reached target Encrypted Volumes.
680:Nov 11 13:01:32 vesoldo systemd[1]: Started Forward Password Requests to Wall Directory Watch.
681:Nov 11 13:01:32 vesoldo systemd[1]: Listening on udev Kernel Socket.
682:Nov 11 13:01:32 vesoldo systemd[1]: Created slice System Slice.
683:Nov 11 13:01:32 vesoldo systemd[1]: Mounting Temporary Directory...
684:Nov 11 13:01:32 vesoldo systemd[1]: Mounting Huge Pages File System...
685:Nov 11 13:01:32 vesoldo systemd[1]: Mounting NFSD configuration filesystem...
686:Nov 11 13:01:32 vesoldo systemd[1]: Mounting Debug File System...
687:Nov 11 13:01:32 vesoldo systemd[1]: Listening on Journal Socket (/dev/log).
688:Nov 11 13:01:32 vesoldo systemd[1]: Starting Journal Service...
689:Nov 11 13:01:32 vesoldo systemd[1]: Created slice system-getty.slice.
690:Nov 11 13:01:32 vesoldo systemd[1]: Starting Setup Virtual Console...
691:Nov 11 13:01:32 vesoldo systemd[1]: Starting Create list of required static device nodes for the current kernel...
692:Nov 11 13:01:32 vesoldo systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
693:Nov 11 13:01:32 vesoldo systemd[1]: Reached target Paths.
694:Nov 11 13:01:32 vesoldo systemd[1]: Created slice User and Session Slice.
695:Nov 11 13:01:32 vesoldo systemd[1]: Reached target Slices.
696:Nov 11 13:01:32 vesoldo systemd[1]: Listening on udev Control Socket.
697:Nov 11 13:01:32 vesoldo systemd[1]: Mounting POSIX Message Queue File System...
698:Nov 11 13:01:32 vesoldo systemd[1]: Starting Remount Root and Kernel File Systems...
699:Nov 11 13:01:32 vesoldo systemd[1]: Starting Load Kernel Modules...
700:Nov 11 13:01:32 vesoldo systemd[1]: Started Create list of required static device nodes for the current kernel.
702:Nov 11 13:01:32 vesoldo systemd[1]: Mounted Debug File System.
703:Nov 11 13:01:32 vesoldo systemd[1]: Mounted Huge Pages File System.
704:Nov 11 13:01:32 vesoldo systemd[1]: Mounted POSIX Message Queue File System.
705:Nov 11 13:01:32 vesoldo systemd[1]: Mounted Temporary Directory.
706:Nov 11 13:01:32 vesoldo systemd[1]: Started Remount Root and Kernel File Systems.
707:Nov 11 13:01:32 vesoldo systemd[1]: Starting udev Coldplug all Devices...
708:Nov 11 13:01:32 vesoldo systemd[1]: Starting Load/Save Random Seed...
709:Nov 11 13:01:32 vesoldo systemd[1]: Starting Create Static Device Nodes in /dev...
715:Nov 11 13:01:32 vesoldo systemd[1]: Started Load/Save Random Seed.
717:Nov 11 13:01:32 vesoldo systemd[1]: Started udev Coldplug all Devices.
719:Nov 11 13:01:32 vesoldo systemd[1]: Mounted NFSD configuration filesystem.
723:Nov 11 13:01:32 vesoldo systemd[1]: Started Load Kernel Modules.
724:Nov 11 13:01:32 vesoldo systemd[1]: Starting Apply Kernel Variables...
725:Nov 11 13:01:32 vesoldo systemd[1]: Mounting Configuration File System...
726:Nov 11 13:01:32 vesoldo systemd[1]: Mounted Configuration File System.
727:Nov 11 13:01:32 vesoldo systemd[1]: Started Apply Kernel Variables.
728:Nov 11 13:01:32 vesoldo systemd[1]: Started Create Static Device Nodes in /dev.
729:Nov 11 13:01:32 vesoldo systemd[1]: Starting udev Kernel Device Manager...
730:Nov 11 13:01:32 vesoldo systemd[1]: Reached target Local File Systems (Pre).
731:Nov 11 13:01:32 vesoldo systemd[1]: Started Setup Virtual Console.
733:Nov 11 13:01:32 vesoldo systemd[1]: Started udev Kernel Device Manager.
748:Nov 11 13:01:32 vesoldo systemd-journald[143]: Journal started
749:Nov 11 13:01:31 vesoldo systemd-modules-load[150]: Inserted module 'nfs'
750:Nov 11 13:01:32 vesoldo systemd[1]: Started Journal Service.
753:Nov 11 13:01:31 vesoldo systemd-modules-load[150]: Inserted module 'vboxdrv'
755:Nov 11 13:01:32 vesoldo systemd[1]: Starting Flush Journal to Persistent Storage...
825:Nov 11 13:01:32 vesoldo systemd[1]: Found device WDC_WD10JPVT-00A1YT0 backup.
826:Nov 11 13:01:32 vesoldo systemd[1]: Mounting /media/backup...
827:Nov 11 13:01:32 vesoldo systemd[1]: Found device TS256GMTS400 usrlocal.
828:Nov 11 13:01:32 vesoldo systemd[1]: Found device TS256GMTS400 home.
829:Nov 11 13:01:32 vesoldo systemd[1]: Found device TS256GMTS400 virtualboxes.
830:Nov 11 13:01:32 vesoldo systemd[1]: Found device WDC_WD10JPVT-00A1YT0 Delta.
831:Nov 11 13:01:32 vesoldo systemd[1]: Found device TS256GMTS400 Documents.
832:Nov 11 13:01:32 vesoldo systemd[1]: Mounting /media/Delta...
833:Nov 11 13:01:32 vesoldo systemd[1]: Mounting /media/virtualboxes...
834:Nov 11 13:01:32 vesoldo systemd[1]: Mounting /home...
835:Nov 11 13:01:32 vesoldo systemd[1]: Mounting /usr/local...
836:Nov 11 13:01:32 vesoldo systemd[1]: Mounted /media/backup.
837:Nov 11 13:01:32 vesoldo systemd[1]: Started Flush Journal to Persistent Storage.
838:Nov 11 13:01:32 vesoldo systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
840:Nov 11 13:01:32 vesoldo systemd[1]: Mounting /home/koen/Documents...
841:Nov 11 13:01:32 vesoldo systemd[1]: Starting Load/Save RF Kill Switch Status...
842:Nov 11 13:01:32 vesoldo systemd[1]: Started Load/Save RF Kill Switch Status.
843:Nov 11 13:01:32 vesoldo systemd[1]: Created slice system-systemd\x2dbacklight.slice.
844:Nov 11 13:01:32 vesoldo systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:intel_backlight...
845:Nov 11 13:01:32 vesoldo systemd[1]: Reached target Sound Card.
846:Nov 11 13:01:32 vesoldo systemd[1]: Mounted /home/koen/Documents.
847:Nov 11 13:01:32 vesoldo systemd[1]: Mounting FUSE Control File System...
848:Nov 11 13:01:32 vesoldo systemd[1]: Mounted FUSE Control File System.
857:Nov 11 13:01:33 vesoldo systemd[1]: Mounted /media/Delta.
858:Nov 11 13:01:33 vesoldo systemd[1]: Reached target Local File Systems.
862:Nov 11 13:01:33 vesoldo systemd[1]: Starting Create Volatile Files and Directories...
865:Nov 11 13:01:33 vesoldo systemd[1]: Starting Preprocess NFS configuration...
866:Nov 11 13:01:33 vesoldo systemd[1]: Started Preprocess NFS configuration.
867:Nov 11 13:01:33 vesoldo systemd[1]: Started Create Volatile Files and Directories.
868:Nov 11 13:01:33 vesoldo systemd[1]: Mounting RPC Pipe File System...
869:Nov 11 13:01:33 vesoldo systemd[1]: Starting Update UTMP about System Boot/Shutdown...
870:Nov 11 13:01:33 vesoldo systemd[1]: Starting Network Time Synchronization...
871:Nov 11 13:01:33 vesoldo systemd[1]: Mounted RPC Pipe File System.
872:Nov 11 13:01:33 vesoldo systemd[1]: Started Update UTMP about System Boot/Shutdown.
873:Nov 11 13:01:33 vesoldo systemd[1]: Started Network Time Synchronization.
874:Nov 11 13:01:33 vesoldo systemd[1]: Reached target System Time Synchronized.
875:Nov 11 13:01:33 vesoldo systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:intel_backlight.
876:Nov 11 13:01:33 vesoldo systemd[1]: Reached target System Initialization.
877:Nov 11 13:01:33 vesoldo systemd[1]: Started Daily locate database update.
878:Nov 11 13:01:33 vesoldo systemd[1]: Listening on RPCbind Server Activation Socket.
879:Nov 11 13:01:33 vesoldo systemd[1]: Started Daily verification of password and group files.
880:Nov 11 13:01:33 vesoldo systemd[1]: Listening on D-Bus System Message Bus Socket.
881:Nov 11 13:01:33 vesoldo systemd[1]: Reached target Sockets.
882:Nov 11 13:01:33 vesoldo systemd[1]: Started Discard unused blocks once a week.
883:Nov 11 13:01:33 vesoldo systemd[1]: Started Daily rotation of log files.
884:Nov 11 13:01:33 vesoldo systemd[1]: Starting Restore Sound Card State...
885:Nov 11 13:01:33 vesoldo systemd[1]: Started Daily man-db cache update.
886:Nov 11 13:01:33 vesoldo systemd[1]: Reached target Basic System.
887:Nov 11 13:01:33 vesoldo systemd[1]: Started Periodic Command Scheduler.
888:Nov 11 13:01:33 vesoldo systemd[1]: Started D-Bus System Message Bus.
928:Nov 11 13:01:33 vesoldo systemd[1]: Starting Laptop Mode Tools...
929:Nov 11 13:01:33 vesoldo systemd[1]: Started ACPI event daemon.
930:Nov 11 13:01:33 vesoldo systemd[1]: Starting Apply cpupower configuration...
931:Nov 11 13:01:33 vesoldo systemd[1]: Starting GSSAPI Proxy Daemon...
932:Nov 11 13:01:33 vesoldo systemd[1]: Starting Network Manager...
933:Nov 11 13:01:33 vesoldo systemd[1]: Starting SSH Key Generation...
934:Nov 11 13:01:33 vesoldo systemd[1]: Starting Bluetooth service...
935:Nov 11 13:01:33 vesoldo systemd[1]: Starting Login Service...
936:Nov 11 13:01:33 vesoldo systemd[1]: Starting Initialize hardware monitoring sensors...
937:Nov 11 13:01:33 vesoldo systemd[1]: Started Daily Cleanup of Temporary Directories.
938:Nov 11 13:01:33 vesoldo systemd[1]: Reached target Timers.
939:Nov 11 13:01:33 vesoldo systemd[1]: Started Restore Sound Card State.
940:Nov 11 13:01:33 vesoldo systemd[1]: Started Apply cpupower configuration.
941:Nov 11 13:01:33 vesoldo systemd[1]: Started Login Service.
942:Nov 11 13:01:33 vesoldo systemd-logind[1085]: New seat seat0.
943:Nov 11 13:01:33 vesoldo systemd[1]: Started Initialize hardware monitoring sensors.
944:Nov 11 13:01:33 vesoldo systemd-logind[1085]: Watching system buttons on /dev/input/event3 (Power Button)
945:Nov 11 13:01:33 vesoldo systemd-logind[1085]: Watching system buttons on /dev/input/event7 (Video Bus)
946:Nov 11 13:01:33 vesoldo systemd-logind[1085]: Watching system buttons on /dev/input/event1 (Lid Switch)
947:Nov 11 13:01:33 vesoldo systemd-logind[1085]: Watching system buttons on /dev/input/event2 (Sleep Button)
948:Nov 11 13:01:33 vesoldo systemd-logind[1085]: Watching system buttons on /dev/input/event4 (ThinkPad Extra Buttons)
951:Nov 11 13:01:33 vesoldo systemd[1]: Started Bluetooth service.
952:Nov 11 13:01:33 vesoldo systemd[1]: Reached target Bluetooth.
958:Nov 11 13:01:33 vesoldo systemd[1]: Starting Hostname Service...
959:Nov 11 13:01:33 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'
973:Nov 11 13:01:34 vesoldo systemd[1]: Started SSH Key Generation.
976:Nov 11 13:01:34 vesoldo systemd[1]: Started GSSAPI Proxy Daemon.
977:Nov 11 13:01:34 vesoldo systemd[1]: Reached target NFS client services.
978:Nov 11 13:01:34 vesoldo systemd[1]: Reached target Remote File Systems (Pre).
979:Nov 11 13:01:34 vesoldo systemd[1]: Reached target Remote File Systems.
980:Nov 11 13:01:34 vesoldo systemd[1]: Starting Permit User Sessions...
981:Nov 11 13:01:34 vesoldo systemd[1]: Started Permit User Sessions.
982:Nov 11 13:01:34 vesoldo systemd[1]: Started Getty on tty1.
983:Nov 11 13:01:34 vesoldo systemd[1]: Reached target Login Prompts.
984:Nov 11 13:01:34 vesoldo systemd[1]: Starting Light Display Manager...
986:Nov 11 13:01:34 vesoldo systemd[1]: Started Hostname Service.
992:Nov 11 13:01:34 vesoldo systemd[1]: Started Network Manager.
993:Nov 11 13:01:34 vesoldo systemd[1]: Reached target Network.
994:Nov 11 13:01:34 vesoldo systemd[1]: Starting Notify NFS peers of a restart...
995:Nov 11 13:01:34 vesoldo systemd[1]: Started OpenSSH Daemon.
997:Nov 11 13:01:34 vesoldo systemd[1]: Started Light Display Manager.
998:Nov 11 13:01:34 vesoldo systemd[1]: Started Notify NFS peers of a restart.
999:Nov 11 13:01:34 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.Accounts' unit='accounts-daemon.service'
1000:Nov 11 13:01:34 vesoldo systemd[1]: Reached target User and Group Name Lookups.
1001:Nov 11 13:01:34 vesoldo systemd[1]: Starting Accounts Service...
1002:Nov 11 13:01:34 vesoldo systemd[1]: Started Laptop Mode Tools.
1003:Nov 11 13:01:34 vesoldo systemd[1]: Reached target Multi-User System.
1004:Nov 11 13:01:34 vesoldo systemd[1]: Reached target Graphical Interface.
1006:Nov 11 13:01:34 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service'
1008:Nov 11 13:01:34 vesoldo systemd[1]: Starting Authorization Manager...
1024:Nov 11 13:01:34 vesoldo systemd[1]: Started Authorization Manager.
1028:Nov 11 13:01:34 vesoldo systemd[1]: Started Accounts Service.
1030:Nov 11 13:01:34 vesoldo systemd[1]: Startup finished in 1.705s (kernel) + 2.800s (userspace) = 4.506s.
1072:Nov 11 13:01:34 vesoldo dbus[1056]: [system] Activating via systemd: service name='fi.w1.wpa_supplicant1' unit='wpa_supplicant.service'
1073:Nov 11 13:01:34 vesoldo systemd[1]: Starting WPA supplicant...
1081:Nov 11 13:01:34 vesoldo systemd[1]: Started WPA supplicant.
1084:Nov 11 13:01:34 vesoldo systemd[1]: Created slice user-620.slice.
1085:Nov 11 13:01:34 vesoldo systemd[1]: Starting User Manager for UID 620...
1086:Nov 11 13:01:34 vesoldo systemd-logind[1085]: New session c1 of user lightdm.
1087:Nov 11 13:01:34 vesoldo systemd[1]: Started Session c1 of user lightdm.
1088:Nov 11 13:01:34 vesoldo systemd[1703]: pam_unix(systemd-user:session): session opened for user lightdm by (uid=0)
1093:Nov 11 13:01:34 vesoldo systemd[1703]: Reached target Paths.
1094:Nov 11 13:01:34 vesoldo systemd[1703]: Starting D-Bus User Message Bus Socket.
1095:Nov 11 13:01:34 vesoldo systemd[1703]: Reached target Timers.
1096:Nov 11 13:01:34 vesoldo systemd[1703]: Listening on Sound System.
1097:Nov 11 13:01:34 vesoldo systemd[1703]: Listening on D-Bus User Message Bus Socket.
1098:Nov 11 13:01:34 vesoldo systemd[1703]: Reached target Sockets.
1099:Nov 11 13:01:34 vesoldo systemd[1703]: Reached target Basic System.
1100:Nov 11 13:01:34 vesoldo systemd[1703]: Reached target Default.
1101:Nov 11 13:01:34 vesoldo systemd[1703]: Startup finished in 25ms.
1102:Nov 11 13:01:34 vesoldo systemd[1]: Started User Manager for UID 620.
1103:Nov 11 13:01:34 vesoldo systemd[1703]: Started D-Bus User Message Bus.
1104:Nov 11 13:01:34 vesoldo dbus-daemon[1711]: Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service'
1105:Nov 11 13:01:34 vesoldo systemd[1703]: Starting Virtual filesystem service...
1107:Nov 11 13:01:34 vesoldo systemd[1703]: Started Virtual filesystem service.
1112:Nov 11 13:01:37 vesoldo systemd-logind[1085]: Removed session c1.
1113:Nov 11 13:01:37 vesoldo systemd[1]: Stopping User Manager for UID 620...
1114:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped target Default.
1115:Nov 11 13:01:37 vesoldo systemd[1703]: Stopping Virtual filesystem service...
1116:Nov 11 13:01:37 vesoldo systemd[1703]: Stopping D-Bus User Message Bus...
1117:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped D-Bus User Message Bus.
1118:Nov 11 13:01:37 vesoldo systemd[1]: Created slice user-1000.slice.
1119:Nov 11 13:01:37 vesoldo systemd[1]: Starting User Manager for UID 1000...
1120:Nov 11 13:01:37 vesoldo systemd-logind[1085]: New session c2 of user koen.
1121:Nov 11 13:01:37 vesoldo systemd[1]: Started Session c2 of user koen.
1122:Nov 11 13:01:37 vesoldo systemd[1750]: pam_unix(systemd-user:session): session opened for user koen by (uid=0)
1123:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped Virtual filesystem service.
1124:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped target Basic System.
1125:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped target Sockets.
1126:Nov 11 13:01:37 vesoldo systemd[1703]: Closed Sound System.
1127:Nov 11 13:01:37 vesoldo systemd[1703]: Closed D-Bus User Message Bus Socket.
1128:Nov 11 13:01:37 vesoldo systemd[1703]: Reached target Shutdown.
1129:Nov 11 13:01:37 vesoldo systemd[1703]: Starting Exit the Session...
1130:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped target Paths.
1131:Nov 11 13:01:37 vesoldo systemd[1703]: Stopped target Timers.
1132:Nov 11 13:01:37 vesoldo systemd[1703]: Received SIGRTMIN+24 from PID 1756 (kill).
1133:Nov 11 13:01:37 vesoldo systemd[1704]: pam_unix(systemd-user:session): session closed for user lightdm
1134:Nov 11 13:01:37 vesoldo systemd[1]: Stopped User Manager for UID 620.
1135:Nov 11 13:01:37 vesoldo systemd[1750]: Reached target Timers.
1136:Nov 11 13:01:37 vesoldo systemd[1750]: Starting D-Bus User Message Bus Socket.
1138:Nov 11 13:01:37 vesoldo systemd[1750]: Listening on Sound System.
1140:Nov 11 13:01:37 vesoldo systemd[1750]: Reached target Paths.
1142:Nov 11 13:01:37 vesoldo systemd[1]: Removed slice user-620.slice.
1144:Nov 11 13:01:37 vesoldo systemd[1750]: Listening on D-Bus User Message Bus Socket.
1146:Nov 11 13:01:37 vesoldo systemd[1750]: Reached target Sockets.
1148:Nov 11 13:01:37 vesoldo systemd[1750]: Reached target Basic System.
1150:Nov 11 13:01:37 vesoldo systemd[1750]: Starting Emacs: the extensible, self-documenting text editor...
1195:Nov 11 13:01:38 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
1196:Nov 11 13:01:38 vesoldo systemd[1]: Starting Network Manager Script Dispatcher Service...
1198:Nov 11 13:01:38 vesoldo systemd[1]: Started Network Manager Script Dispatcher Service.
1228:Nov 11 13:02:02 vesoldo lightdm[1737]: pam_systemd(lightdm:session): Failed to create session: Connection timed out
1230:Nov 11 13:02:03 vesoldo systemd[1]: Reached target RPC Port Mapper.
1231:Nov 11 13:02:03 vesoldo systemd[1]: Reached target Host and Network Name Lookups.
1232:Nov 11 13:02:03 vesoldo systemd[1]: Starting NFS status monitor for NFSv2/3 locking....
1235:Nov 11 13:02:03 vesoldo systemd[1]: Starting RPC bind service...
1236:Nov 11 13:02:03 vesoldo systemd[1]: Started RPC bind service.
1238:Nov 11 13:02:03 vesoldo systemd[1]: Started NFS status monitor for NFSv2/3 locking..
1243:Nov 11 13:02:03 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service'
1244:Nov 11 13:02:03 vesoldo systemd[1]: Starting Daemon for power management...
1246:Nov 11 13:02:03 vesoldo systemd[1]: Started Daemon for power management.
1247:Nov 11 13:02:03 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service'
1248:Nov 11 13:02:03 vesoldo systemd[1]: Starting Disk Manager...
1254:Nov 11 13:02:03 vesoldo systemd[1]: Started Disk Manager.
1271:Nov 11 13:02:06 vesoldo dbus[1056]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service'
1272:Nov 11 13:02:06 vesoldo systemd[1]: Starting Manage, Install and Generate Color Profiles...
1278:Nov 11 13:02:06 vesoldo systemd[1]: Started Manage, Install and Generate Color Profiles.
1284:Nov 11 13:02:13 vesoldo systemd-timesyncd[1047]: Timed out waiting for reply from 198.50.135.212:123 (2.arch.pool.ntp.org).
1285:Nov 11 13:02:13 vesoldo systemd-timesyncd[1047]: Synchronized to time server 206.248.144.162:123 (2.arch.pool.ntp.org).
1304:Nov 11 13:03:07 vesoldo systemd[1]: user@1000.service: Start operation timed out. Terminating.
1305:Nov 11 13:03:07 vesoldo systemd[1750]: Stopped target Default.
1307:Nov 11 13:03:08 vesoldo systemd[1750]: Stopped Emacs: the extensible, self-documenting text editor.
1308:Nov 11 13:03:08 vesoldo systemd[1750]: Stopped target Basic System.
1309:Nov 11 13:03:08 vesoldo systemd[1750]: Stopped target Paths.
1310:Nov 11 13:03:08 vesoldo systemd[1750]: Stopped target Timers.
1311:Nov 11 13:03:08 vesoldo systemd[1750]: Stopped target Sockets.
1312:Nov 11 13:03:08 vesoldo systemd[1750]: Closed D-Bus User Message Bus Socket.
1313:Nov 11 13:03:08 vesoldo systemd[1750]: Closed Sound System.
1314:Nov 11 13:03:08 vesoldo systemd[1750]: Reached target Shutdown.
1315:Nov 11 13:03:08 vesoldo systemd[1750]: Starting Exit the Session...
1316:Nov 11 13:03:08 vesoldo systemd[1750]: Received SIGRTMIN+24 from PID 2268 (kill).
1317:Nov 11 13:03:08 vesoldo systemd[1751]: pam_unix(systemd-user:session): session closed for user koen
1318:Nov 11 13:03:08 vesoldo systemd[1]: Failed to start User Manager for UID 1000.
1319:Nov 11 13:03:08 vesoldo systemd[1]: user@1000.service: Unit entered failed state.
1320:Nov 11 13:03:08 vesoldo systemd[1]: user@1000.service: Failed with result 'timeout'.

Note the large time-out delay before

 1228:Nov 11 13:02:02 vesoldo lightdm[1737]: pam_systemd(lightdm:session): Failed to create session: Connection timed out

This delay is between attempted login through lightdm and the actual start of the DE (Cinnamon).

This seems similar to the issue in https://bbs.archlinux.org/viewtopic.php?id=180641, but I do not use readahead for systemd, and it seems to me like the Wiki at https://wiki.archlinux.org/index.php/Systemd/User is just saying that the "systemd --user" instance should work out of the box with the newest systemd and dbus packages. Of course I have fully upgraded my system, so this shouldn't be a problem.

I have tried to downgrade systemd and dbus to before I had this problem, with no result.

I can't find any more information on this problem elsewhere, on the Forum or the Wiki. Can anyone help me resolve this, or point me in the right direction? Even help on how to debug the errors I am getting would be appreciated.

Thank you in advance for any help!

Last edited by koen (2015-11-12 21:08:23)

jasonwryan · 2015-11-11 21:31:04

1086:Nov 11 13:01:34 vesoldo systemd-logind[1085]: New session c1 of user lightdm.
1087:Nov 11 13:01:34 vesoldo systemd[1]: Started Session c1 of user lightdm.
1088:Nov 11 13:01:34 vesoldo systemd[1703]: pam_unix(systemd-user:session): session opened for user lightdm by (uid=0)

...and without lightdm?

koen · 2015-11-11 21:40:01

Un fortunately, that doesn't resolve it. I disabled lightdm temporarily, and this is what I get:

[koen@vesoldo: ~]$ journalctl -b | grep systemd
2:Nov 11 13:34:42 vesoldo systemd-journald[162]: Runtime journal (/run/log/journal/) is currently using 8.0M.
6:Nov 11 13:34:42 vesoldo systemd-journald[162]: System journal (/var/log/journal/) is currently using 944.1M.
10:Nov 11 13:34:43 vesoldo systemd-journald[162]: Time spent on flushing to /var is 129.706ms for 2 entries.
563:Nov 11 13:34:43 vesoldo kernel: random: systemd-tmpfile urandom read with 3 bits of entropy available
669:Nov 11 13:34:43 vesoldo systemd[1]: systemd 227 running in system mode. (+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID -ELFUTILS +KMOD +IDN)
670:Nov 11 13:34:43 vesoldo systemd[1]: Detected architecture x86-64.
671:Nov 11 13:34:43 vesoldo systemd[1]: Set hostname to <vesoldo>.
673:Nov 11 13:34:43 vesoldo systemd[1]: display-manager.service: Cannot add dependency job, ignoring: Unit display-manager.service failed to load: No such file or directory.
674:Nov 11 13:34:43 vesoldo systemd[1]: Started Forward Password Requests to Wall Directory Watch.
675:Nov 11 13:34:43 vesoldo systemd[1]: Listening on Journal Socket (/dev/log).
676:Nov 11 13:34:43 vesoldo systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
677:Nov 11 13:34:43 vesoldo systemd[1]: Listening on Journal Socket.
678:Nov 11 13:34:43 vesoldo systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
679:Nov 11 13:34:43 vesoldo systemd[1]: Listening on udev Kernel Socket.
680:Nov 11 13:34:43 vesoldo systemd[1]: Reached target Encrypted Volumes.
681:Nov 11 13:34:43 vesoldo systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
682:Nov 11 13:34:43 vesoldo systemd[1]: Reached target Paths.
683:Nov 11 13:34:43 vesoldo systemd[1]: Listening on LVM2 metadata daemon socket.
684:Nov 11 13:34:43 vesoldo systemd[1]: Created slice User and Session Slice.
685:Nov 11 13:34:43 vesoldo systemd[1]: Listening on Device-mapper event daemon FIFOs.
686:Nov 11 13:34:43 vesoldo systemd[1]: Listening on udev Control Socket.
687:Nov 11 13:34:43 vesoldo systemd[1]: Reached target Swap.
688:Nov 11 13:34:43 vesoldo systemd[1]: Created slice System Slice.
689:Nov 11 13:34:43 vesoldo systemd[1]: Created slice system-getty.slice.
690:Nov 11 13:34:43 vesoldo systemd[1]: Mounting POSIX Message Queue File System...
691:Nov 11 13:34:43 vesoldo systemd[1]: Starting Setup Virtual Console...
692:Nov 11 13:34:43 vesoldo systemd[1]: Reached target Slices.
693:Nov 11 13:34:43 vesoldo systemd[1]: Starting Create list of required static device nodes for the current kernel...
694:Nov 11 13:34:43 vesoldo systemd[1]: Mounting Debug File System...
695:Nov 11 13:34:43 vesoldo systemd[1]: Mounting Temporary Directory...
696:Nov 11 13:34:43 vesoldo systemd[1]: Starting Load Kernel Modules...
697:Nov 11 13:34:43 vesoldo systemd[1]: Mounting Huge Pages File System...
698:Nov 11 13:34:43 vesoldo systemd[1]: Starting Remount Root and Kernel File Systems...
699:Nov 11 13:34:43 vesoldo systemd[1]: Starting Journal Service...
700:Nov 11 13:34:43 vesoldo systemd[1]: Mounting NFSD configuration filesystem...
701:Nov 11 13:34:43 vesoldo systemd[1]: Started Create list of required static device nodes for the current kernel.
703:Nov 11 13:34:43 vesoldo systemd[1]: Mounted Debug File System.
704:Nov 11 13:34:43 vesoldo systemd[1]: Started Remount Root and Kernel File Systems.
706:Nov 11 13:34:43 vesoldo systemd[1]: Mounted Huge Pages File System.
707:Nov 11 13:34:43 vesoldo systemd[1]: Starting udev Coldplug all Devices...
708:Nov 11 13:34:43 vesoldo systemd[1]: Starting Load/Save Random Seed...
709:Nov 11 13:34:43 vesoldo systemd[1]: Starting Create Static Device Nodes in /dev...
710:Nov 11 13:34:43 vesoldo systemd[1]: Mounted POSIX Message Queue File System.
711:Nov 11 13:34:43 vesoldo systemd[1]: Mounted Temporary Directory.
716:Nov 11 13:34:43 vesoldo systemd[1]: Started Load/Save Random Seed.
719:Nov 11 13:34:43 vesoldo systemd[1]: Started udev Coldplug all Devices.
723:Nov 11 13:34:43 vesoldo systemd[1]: Started Load Kernel Modules.
724:Nov 11 13:34:43 vesoldo systemd[1]: Mounting Configuration File System...
725:Nov 11 13:34:43 vesoldo systemd[1]: Starting Apply Kernel Variables...
726:Nov 11 13:34:43 vesoldo systemd[1]: Mounted NFSD configuration filesystem.
727:Nov 11 13:34:43 vesoldo systemd[1]: Mounted Configuration File System.
728:Nov 11 13:34:43 vesoldo systemd[1]: Started Apply Kernel Variables.
729:Nov 11 13:34:43 vesoldo systemd[1]: Started Create Static Device Nodes in /dev.
730:Nov 11 13:34:43 vesoldo systemd[1]: Reached target Local File Systems (Pre).
731:Nov 11 13:34:43 vesoldo systemd[1]: Starting udev Kernel Device Manager...
732:Nov 11 13:34:43 vesoldo systemd[1]: Started Setup Virtual Console.
734:Nov 11 13:34:43 vesoldo systemd[1]: Started udev Kernel Device Manager.
745:Nov 11 13:34:43 vesoldo systemd-journald[162]: Journal started
746:Nov 11 13:34:43 vesoldo systemd-modules-load[159]: Inserted module 'nfs'
747:Nov 11 13:34:43 vesoldo systemd[1]: Started Journal Service.
751:Nov 11 13:34:42 vesoldo systemd-modules-load[159]: Inserted module 'vboxdrv'
753:Nov 11 13:34:43 vesoldo systemd[1]: Starting Flush Journal to Persistent Storage...
831:Nov 11 13:34:43 vesoldo systemd[1]: Found device WDC_WD10JPVT-00A1YT0 backup.
832:Nov 11 13:34:43 vesoldo systemd[1]: Mounting /media/backup...
833:Nov 11 13:34:43 vesoldo systemd[1]: Found device TS256GMTS400 home.
834:Nov 11 13:34:43 vesoldo systemd[1]: Found device TS256GMTS400 usrlocal.
835:Nov 11 13:34:43 vesoldo systemd[1]: Found device WDC_WD10JPVT-00A1YT0 Delta.
836:Nov 11 13:34:43 vesoldo systemd[1]: Found device TS256GMTS400 virtualboxes.
837:Nov 11 13:34:43 vesoldo systemd[1]: Found device TS256GMTS400 Documents.
838:Nov 11 13:34:43 vesoldo systemd[1]: Mounting /media/virtualboxes...
839:Nov 11 13:34:43 vesoldo systemd[1]: Mounting /media/Delta...
840:Nov 11 13:34:43 vesoldo systemd[1]: Mounting /usr/local...
841:Nov 11 13:34:43 vesoldo systemd[1]: Mounting /home...
842:Nov 11 13:34:43 vesoldo systemd[1]: Reached target Sound Card.
843:Nov 11 13:34:43 vesoldo systemd[1]: Starting Load/Save RF Kill Switch Status...
844:Nov 11 13:34:43 vesoldo systemd[1]: Mounting /home/koen/Documents...
845:Nov 11 13:34:43 vesoldo systemd[1]: Mounted FUSE Control File System.
846:Nov 11 13:34:43 vesoldo systemd[1]: Started Load/Save RF Kill Switch Status.
847:Nov 11 13:34:43 vesoldo systemd[1]: Started Flush Journal to Persistent Storage.
848:Nov 11 13:34:43 vesoldo systemd[1]: Mounted /home/koen/Documents.
859:Nov 11 13:34:44 vesoldo systemd[1]: Mounted /media/Delta.
861:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Local File Systems.
863:Nov 11 13:34:44 vesoldo systemd[1]: Starting Preprocess NFS configuration...
865:Nov 11 13:34:44 vesoldo systemd[1]: Starting Create Volatile Files and Directories...
866:Nov 11 13:34:44 vesoldo systemd[1]: Started Preprocess NFS configuration.
867:Nov 11 13:34:44 vesoldo systemd[1]: Started Create Volatile Files and Directories.
868:Nov 11 13:34:44 vesoldo systemd[1]: Starting Update UTMP about System Boot/Shutdown...
869:Nov 11 13:34:44 vesoldo systemd[1]: Mounting RPC Pipe File System...
870:Nov 11 13:34:44 vesoldo systemd[1]: Starting Network Time Synchronization...
871:Nov 11 13:34:44 vesoldo systemd[1]: Mounted RPC Pipe File System.
872:Nov 11 13:34:44 vesoldo systemd[1]: Started Update UTMP about System Boot/Shutdown.
873:Nov 11 13:34:44 vesoldo systemd[1]: Started Network Time Synchronization.
874:Nov 11 13:34:44 vesoldo systemd[1]: Reached target System Initialization.
875:Nov 11 13:34:44 vesoldo systemd[1]: Listening on D-Bus System Message Bus Socket.
876:Nov 11 13:34:44 vesoldo systemd[1]: Started Daily Cleanup of Temporary Directories.
877:Nov 11 13:34:44 vesoldo systemd[1]: Listening on RPCbind Server Activation Socket.
878:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Sockets.
879:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Basic System.
880:Nov 11 13:34:44 vesoldo systemd[1]: Starting Apply cpupower configuration...
881:Nov 11 13:34:44 vesoldo systemd[1]: Starting GSSAPI Proxy Daemon...
882:Nov 11 13:34:44 vesoldo systemd[1]: Starting Laptop Mode Tools...
883:Nov 11 13:34:44 vesoldo systemd[1]: Started Periodic Command Scheduler.
884:Nov 11 13:34:44 vesoldo systemd[1]: Starting Network Manager...
885:Nov 11 13:34:44 vesoldo systemd[1]: Starting Login Service...
886:Nov 11 13:34:44 vesoldo systemd[1]: Starting SSH Key Generation...
887:Nov 11 13:34:44 vesoldo systemd[1]: Starting Initialize hardware monitoring sensors...
888:Nov 11 13:34:44 vesoldo systemd[1]: Started ACPI event daemon.
889:Nov 11 13:34:44 vesoldo systemd[1]: Starting Bluetooth service...
890:Nov 11 13:34:44 vesoldo systemd[1]: Started D-Bus System Message Bus.
898:Nov 11 13:34:44 vesoldo systemd[1]: Starting Restore Sound Card State...
899:Nov 11 13:34:44 vesoldo systemd[1]: Reached target System Time Synchronized.
900:Nov 11 13:34:44 vesoldo systemd[1]: Started Daily rotation of log files.
901:Nov 11 13:34:44 vesoldo systemd[1]: Started Daily man-db cache update.
902:Nov 11 13:34:44 vesoldo systemd[1]: Started Daily verification of password and group files.
903:Nov 11 13:34:44 vesoldo systemd[1]: Started Discard unused blocks once a week.
904:Nov 11 13:34:44 vesoldo systemd[1]: Started Daily locate database update.
905:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Timers.
906:Nov 11 13:34:44 vesoldo systemd[1]: Started Apply cpupower configuration.
907:Nov 11 13:34:44 vesoldo systemd[1]: Started GSSAPI Proxy Daemon.
908:Nov 11 13:34:44 vesoldo systemd[1]: Started SSH Key Generation.
909:Nov 11 13:34:44 vesoldo systemd[1]: Started Restore Sound Card State.
910:Nov 11 13:34:44 vesoldo systemd[1]: Reached target NFS client services.
911:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Remote File Systems (Pre).
912:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Remote File Systems.
913:Nov 11 13:34:44 vesoldo systemd-logind[1549]: Watching system buttons on /dev/input/event3 (Power Button)
914:Nov 11 13:34:44 vesoldo systemd[1]: Starting Permit User Sessions...
915:Nov 11 13:34:44 vesoldo systemd-logind[1549]: Watching system buttons on /dev/input/event6 (Video Bus)
916:Nov 11 13:34:44 vesoldo systemd-logind[1549]: Watching system buttons on /dev/input/event1 (Lid Switch)
917:Nov 11 13:34:44 vesoldo systemd-logind[1549]: Watching system buttons on /dev/input/event2 (Sleep Button)
918:Nov 11 13:34:44 vesoldo systemd[1]: Started Login Service.
919:Nov 11 13:34:44 vesoldo systemd-logind[1549]: Watching system buttons on /dev/input/event4 (ThinkPad Extra Buttons)
920:Nov 11 13:34:44 vesoldo systemd[1]: Started Permit User Sessions.
923:Nov 11 13:34:44 vesoldo dbus[1555]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'
1019:Nov 11 13:34:44 vesoldo systemd[1]: Started Getty on tty1.
1020:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Login Prompts.
1021:Nov 11 13:34:44 vesoldo systemd-logind[1549]: New seat seat0.
1022:Nov 11 13:34:44 vesoldo systemd[1]: Started Initialize hardware monitoring sensors.
1023:Nov 11 13:34:44 vesoldo systemd[1]: Started Bluetooth service.
1024:Nov 11 13:34:44 vesoldo systemd[1]: Started Network Manager.
1025:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Network.
1026:Nov 11 13:34:44 vesoldo systemd[1]: Started OpenSSH Daemon.
1027:Nov 11 13:34:44 vesoldo systemd[1]: Starting Notify NFS peers of a restart...
1028:Nov 11 13:34:44 vesoldo systemd[1]: Starting Hostname Service...
1029:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Bluetooth.
1031:Nov 11 13:34:44 vesoldo systemd[1]: Started Notify NFS peers of a restart.
1032:Nov 11 13:34:44 vesoldo systemd[1]: Created slice system-systemd\x2dbacklight.slice.
1033:Nov 11 13:34:44 vesoldo systemd[1]: Starting Load/Save Screen Backlight Brightness of backlight:intel_backlight...
1034:Nov 11 13:34:44 vesoldo systemd[1]: Started Load/Save Screen Backlight Brightness of backlight:intel_backlight.
1039:Nov 11 13:34:44 vesoldo dbus[1555]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service'
1040:Nov 11 13:34:44 vesoldo dbus[1555]: [system] Activating via systemd: service name='fi.w1.wpa_supplicant1' unit='wpa_supplicant.service'
1041:Nov 11 13:34:44 vesoldo systemd[1]: Starting WPA supplicant...
1042:Nov 11 13:34:44 vesoldo systemd[1]: Starting Authorization Manager...
1054:Nov 11 13:34:44 vesoldo systemd[1]: Started WPA supplicant.
1056:Nov 11 13:34:44 vesoldo systemd[1]: Started Hostname Service.
1061:Nov 11 13:34:44 vesoldo systemd[1]: Started Authorization Manager.
1070:Nov 11 13:34:44 vesoldo systemd[1]: Started Laptop Mode Tools.
1071:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Multi-User System.
1072:Nov 11 13:34:44 vesoldo systemd[1]: Reached target Graphical Interface.
1073:Nov 11 13:34:44 vesoldo systemd[1]: Startup finished in 1.623s (kernel) + 2.511s (userspace) = 4.135s.
1081:Nov 11 13:34:55 vesoldo systemd[1]: Created slice user-1000.slice.
1094:Nov 11 13:34:55 vesoldo systemd[1]: Starting User Manager for UID 1000...
1095:Nov 11 13:34:55 vesoldo systemd-logind[1549]: New session c1 of user koen.
1096:Nov 11 13:34:55 vesoldo systemd[1]: Started Session c1 of user koen.
1097:Nov 11 13:34:55 vesoldo systemd[2171]: pam_unix(systemd-user:session): session opened for user koen by (uid=0)
1099:Nov 11 13:34:56 vesoldo systemd[2171]: Listening on Sound System.
1100:Nov 11 13:34:56 vesoldo systemd[2171]: Starting D-Bus User Message Bus Socket.
1101:Nov 11 13:34:56 vesoldo systemd[2171]: Reached target Timers.
1102:Nov 11 13:34:56 vesoldo systemd[2171]: Reached target Paths.
1103:Nov 11 13:34:56 vesoldo systemd[2171]: Listening on D-Bus User Message Bus Socket.
1104:Nov 11 13:34:56 vesoldo systemd[2171]: Reached target Sockets.
1105:Nov 11 13:34:56 vesoldo systemd[2171]: Reached target Basic System.
1106:Nov 11 13:34:56 vesoldo systemd[2171]: Starting Emacs: the extensible, self-documenting text editor...
1163:Nov 11 13:34:59 vesoldo dbus[1555]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
1164:Nov 11 13:34:59 vesoldo systemd[1]: Starting Network Manager Script Dispatcher Service...
1166:Nov 11 13:34:59 vesoldo systemd[1]: Started Network Manager Script Dispatcher Service.
1176:Nov 11 13:35:01 vesoldo systemd[1]: Reached target RPC Port Mapper.
1177:Nov 11 13:35:01 vesoldo systemd[1]: Reached target Host and Network Name Lookups.
1178:Nov 11 13:35:01 vesoldo systemd[1]: Starting NFS status monitor for NFSv2/3 locking....
1181:Nov 11 13:35:01 vesoldo systemd[1]: Starting RPC bind service...
1182:Nov 11 13:35:01 vesoldo systemd[1]: Started RPC bind service.
1184:Nov 11 13:35:01 vesoldo systemd[1]: Started NFS status monitor for NFSv2/3 locking..
1192:Nov 11 13:35:15 vesoldo systemd-timesyncd[1541]: Synchronized to time server 167.114.101.89:123 (2.arch.pool.ntp.org).
1193:Nov 11 13:35:20 vesoldo login[1569]: pam_systemd(login:session): Failed to create session: Connection timed out
1211:Nov 11 13:36:26 vesoldo systemd[2171]: emacs.service: Start operation timed out. Terminating.
1212:Nov 11 13:36:26 vesoldo systemd[1]: user@1000.service: Start operation timed out. Terminating.
1213:Nov 11 13:36:26 vesoldo systemd[2171]: Stopped Emacs: the extensible, self-documenting text editor.
1214:Nov 11 13:36:26 vesoldo systemd[2171]: emacs.service: Unit entered failed state.
1215:Nov 11 13:36:26 vesoldo systemd[2171]: emacs.service: Failed with result 'timeout'.
1216:Nov 11 13:36:26 vesoldo systemd[2171]: Stopped target Default.
1217:Nov 11 13:36:26 vesoldo systemd[2171]: Stopped target Basic System.
1218:Nov 11 13:36:26 vesoldo systemd[2171]: Stopped target Timers.
1219:Nov 11 13:36:26 vesoldo systemd[2171]: Stopped target Sockets.
1220:Nov 11 13:36:26 vesoldo systemd[2171]: Closed Sound System.
1221:Nov 11 13:36:26 vesoldo systemd[2171]: Stopped target Paths.
1222:Nov 11 13:36:26 vesoldo systemd[2171]: Closed D-Bus User Message Bus Socket.
1223:Nov 11 13:36:26 vesoldo systemd[2171]: Reached target Shutdown.
1224:Nov 11 13:36:26 vesoldo systemd[2171]: Starting Exit the Session...
1225:Nov 11 13:36:26 vesoldo systemd[2171]: Received SIGRTMIN+24 from PID 2391 (kill).
1226:Nov 11 13:36:26 vesoldo systemd[2172]: pam_unix(systemd-user:session): session closed for user koen
1227:Nov 11 13:36:26 vesoldo systemd[1]: Failed to start User Manager for UID 1000.
1228:Nov 11 13:36:26 vesoldo systemd[1]: user@1000.service: Unit entered failed state.
1229:Nov 11 13:36:26 vesoldo systemd[1]: user@1000.service: Failed with result 'timeout'.

koen · 2015-11-12 09:18:51

Okay, I did some more research on what could have gone wrong. I read what pam_systemd is supposed to do (at http://www.freedesktop.org/software/sys … stemd.html) to try and find out where it went bad.

The first thing that seems to go wrong is the pam_systemd doesn't set the XDG_SESSION_ID and XDG_RUNTIME_DIR variables. When logged in, "echo $XDG_SESSION_ID" gives nothing. This may explain why the systemd --user instance is not started correctly: this is result when I try to do it manually

[koen@vesoldo: system]$ sudo /usr/lib/systemd/systemd --user
Trying to run as user instance, but $XDG_RUNTIME_DIR is not set.

Finally, after testing the problem with the root user and with an additional user created for test purposes, I can confirm that this is only a problem for my main user... I can log into the test user just fine, and it starts the user@1001.service just fine, as seen below:

● vesoldo
    State: degraded
     Jobs: 0 queued
   Failed: 1 units
    Since: Thu 2015-11-12 01:01:50 PST; 14min ago
   CGroup: /
           ├─init.scope
           │ └─1 /sbin/init
           ├─system.slice
           │ ├─dbus.service
           │ │ └─751 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation
           │ ├─wpa_supplicant.service
           │ │ └─1576 /usr/bin/wpa_supplicant -u
           │ ├─lightdm.service
           │ │ ├─1571 /usr/bin/lightdm
           │ │ └─1613 /usr/lib/xorg-server/Xorg :0 -seat seat0 -auth /run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch
           │ ├─accounts-daemon.service
           │ │ └─1614 /usr/lib/accountsservice/accounts-daemon
           │ ├─colord.service
           │ │ └─1980 /usr/lib/colord/colord
           │ ├─systemd-journald.service
           │ │ └─146 /usr/lib/systemd/systemd-journald
           │ ├─udisks2.service
           │ │ └─1963 /usr/lib/udisks2/udisksd --no-debug
           │ ├─gssproxy.service
           │ │ └─1086 /usr/bin/gssproxy -D
           │ ├─upower.service
           │ │ └─1940 /usr/lib/upower/upowerd
           │ ├─systemd-timesyncd.service
           │ │ └─652 /usr/lib/systemd/systemd-timesyncd
           │ ├─systemd-logind.service
           │ │ └─735 /usr/lib/systemd/systemd-logind
           │ ├─media-Delta.mount
           │ │ └─588 /sbin/mount.ntfs-3g /dev/sda1 /media/Delta -o rw,permissions,uid=1000,gid=1000,fmask=133,dmask=022
           │ ├─sshd.service
           │ │ └─1580 /usr/bin/sshd -D
           │ ├─systemd-udevd.service
           │ │ └─185 /usr/lib/systemd/systemd-udevd
           │ ├─polkit.service
           │ │ └─1577 /usr/lib/polkit-1/polkitd --no-debug
           │ ├─NetworkManager.service
           │ │ ├─ 748 /usr/bin/NetworkManager --no-daemon
           │ │ └─1818 /usr/bin/dhclient -d -q -sf /usr/lib/networkmanager/nm-dhcp-helper -pf /var/run/dhclient-wlp3s0.pid -lf /var/lib/NetworkManager/dhclient
           │ ├─cronie.service
           │ │ └─734 /usr/bin/crond -n
           │ ├─acpid.service
           │ │ └─749 /usr/bin/acpid --foreground --netlink
           │ └─bluetooth.service
           │   └─736 /usr/lib/bluetooth/bluetoothd
           └─user.slice
             ├─user-1000.slice
             │ └─session-c3.scope
             │   ├─1668 lightdm --session-child 12 19
             │   ├─1872 /usr/bin/gnome-keyring-daemon --daemonize --login
             │   ├─1874 cinnamon-session --session cinnamon
             │   ├─1882 xbindkeys
             │   ├─1889 dbus-launch --autolaunch e5cddbca6a3c471db26d2f12eef1ce9a --binary-syntax --close-stderr
             │   ├─1890 /usr/bin/dbus-daemon --fork --print-pid 5 --print-address 7 --session
             │   ├─1893 dbus-launch --exit-with-session cinnamon-session --session cinnamon
             │   ├─1894 /usr/bin/dbus-daemon --fork --print-pid 5 --print-address 7 --session
             │   ├─1898 /usr/lib/gvfs/gvfsd
           │ ├─polkit.service
           │ │ └─1577 /usr/lib/polkit-1/polkitd --no-debug
           │ ├─NetworkManager.service
           │ │ ├─ 748 /usr/bin/NetworkManager --no-daemon
           │ │ └─1818 /usr/bin/dhclient -d -q -sf /usr/lib/networkmanager/nm-dhcp-helper -pf /var/run/dhclient-wlp3s0.pid -lf /var/lib/NetworkManager/dhclient
           │ ├─cronie.service
           │ │ └─734 /usr/bin/crond -n
           │ ├─acpid.service
           │ │ └─749 /usr/bin/acpid --foreground --netlink
           │ └─bluetooth.service
           │   └─736 /usr/lib/bluetooth/bluetoothd
           └─user.slice
             ├─user-1000.slice
             │ └─session-c3.scope
             │   ├─1668 lightdm --session-child 12 19
             │   ├─1872 /usr/bin/gnome-keyring-daemon --daemonize --login
             │   ├─1874 cinnamon-session --session cinnamon
             │   ├─1882 xbindkeys
             │   ├─1889 dbus-launch --autolaunch e5cddbca6a3c471db26d2f12eef1ce9a --binary-syntax --close-stderr
             │   ├─1890 /usr/bin/dbus-daemon --fork --print-pid 5 --print-address 7 --session
             │   ├─1893 dbus-launch --exit-with-session cinnamon-session --session cinnamon
             │   ├─1894 /usr/bin/dbus-daemon --fork --print-pid 5 --print-address 7 --session
             │   ├─1898 /usr/lib/gvfs/gvfsd
             │   ├─1903 /usr/lib/gvfs/gvfsd-fuse /home/koen/.gvfs -f -o big_writes
             │   ├─1912 /usr/lib/at-spi2-core/at-spi-bus-launcher
             │   ├─1917 /usr/bin/dbus-daemon --config-file=/etc/at-spi2/accessibility.conf --nofork --print-address 3
             │   ├─1919 /usr/lib/at-spi2-core/at-spi2-registryd --use-gnome-session
             │   ├─1925 /usr/lib/cinnamon-settings-daemon/cinnamon-settings-daemon
             │   ├─1960 /usr/lib/gvfs/gvfs-udisks2-volume-monitor
             │   ├─1979 /usr/bin/python2 /usr/bin/cinnamon-launcher
             │   ├─1985 syndaemon -i 1.0 -t -K -R
             │   ├─1987 /usr/lib/cinnamon-settings-daemon/csd-printer
             │   ├─1995 cinnamon --replace
             │   ├─2002 nemo -n
             │   ├─2003 nm-applet
             │   ├─2004 /usr/bin/python2 /usr/bin/cinnamon-killer-daemon
             │   ├─2006 /usr/lib/polkit-gnome/polkit-gnome-authentication-agent-1
             │   ├─2013 python3 /usr/bin/redshift-gtk
             │   ├─2014 python2 -m guake.main
             │   ├─2038 /usr/lib/gvfs/gvfsd-trash --spawner :1.1 /org/gtk/gvfs/exec_spaw/0
             │   ├─2045 /usr/lib/GConf/gconfd-2
             │   ├─2048 /usr/lib/gvfs/gvfsd-metadata
             │   ├─2057 /usr/bin/redshift -v
             │   ├─2061 /bin/bash
             │   ├─2076 /home/koen/.dropbox-dist/dropbox-lnx.x86_64-3.10.11/dropbox /newerversion
             │   ├─2157 /usr/lib/firefox/firefox
             │   ├─2252 cinnamon-screensaver
             │   ├─2310 xfce4-terminal
             │   ├─2314 bash
             │   ├─2486 bash
             │   ├─2490 systemctl status
             │   └─2491 less
             └─user-1001.slice
               ├─session-c6.scope
               │ ├─2452 login -- test     
               │ └─2466 -bash
               └─user@1001.service
                 └─init.scope
                   ├─2459 /usr/lib/systemd/systemd --user
                   └─2461 (sd-pam)

Does anyone have any idea what might be causing this? Thanks!

koen · 2015-11-12 20:14:02

Hey again,

I finally managed to resolve the issue, but it's not very satisfying... All the errors went away when I removed the systemd unit that I had created for the emacs daemon, originally created exactly as described here: https://wiki.archlinux.org/index.php/Emacs#As_a_daemon. I had placed the emacs.service file in ~/.config/systemd/user/.

I'm glad that the issue is fixed, but now I have to find a different way of automatically starting the emacs daemon. If anyone has any ideas of what might have cause this, let me know.

c0mm0ner · 2015-11-12 20:45:32

You can start it using ~/.xprofile

koen · 2015-11-12 21:06:10

Okay, I feel really stupid now, but I figured it out... There was some trouble with the .emacs file, so the emacs daemon was stopping the whole show. It took a long time to figure out.

Thanks for the help though!

Arch Linux

#1 2015-11-11 21:20:18

[SOLVED] "systemd --user" instance not working, results in login-pr...

#2 2015-11-11 21:31:04

Re: [SOLVED] "systemd --user" instance not working, results in login-pr...

#3 2015-11-11 21:40:01

Re: [SOLVED] "systemd --user" instance not working, results in login-pr...

#4 2015-11-12 09:18:51

Re: [SOLVED] "systemd --user" instance not working, results in login-pr...

#5 2015-11-12 20:14:02

Re: [SOLVED] "systemd --user" instance not working, results in login-pr...

#6 2015-11-12 20:45:32

Re: [SOLVED] "systemd --user" instance not working, results in login-pr...

#7 2015-11-12 21:06:10

Re: [SOLVED] "systemd --user" instance not working, results in login-pr...

Board footer