après update de la testing, KDM met 4 minutes à se lancer

grnahuit · 22-07-2014 23:30:56

Bonjour à tous,

j'ai mis à jour ma debian testing qui fonctionnait parfaitement sur mon PC portable ...et depuis kdm met 2 minutes à faire apparaitre la fenetre de login. En attendant ces deux minutes, il y a un tty avec un simple prompt de login

ci-dessous des logs qui montrent le phénomène inexplicable pour l'instant : ça bulle de 23:09 à 23:14 ....

/var/log/messages :

Jul 20 23:09:51 grandhuit NetworkManager[726]: <info> NetworkManager state is now CONNECTED_GLOBAL

Jul 20 23:09:51 grandhuit NetworkManager[726]: <info> WiFi now disabled by radio killswitch

Jul 20 23:09:51 grandhuit NetworkManager[726]: <info> ModemManager disappeared from bus

Jul 20 23:09:51 grandhuit NetworkManager[726]: <info> ModemManager available in the bus

Jul 20 23:14:44 grandhuit org.a11y.Bus[1308]: Activating service name='org.a11y.atspi.Registry'

Jul 20 23:14:44 grandhuit org.a11y.Bus[1308]: Successfully activated service 'org.a11y.atspi.Registry'

Jul 20 23:14:44 grandhuit org.a11y.atspi.Registry[1394]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry

Jul 20 23:14:44 grandhuit org.a11y.atspi.Registry[1394]: ** (at-spi2-registryd:1397): WARNING **: Failed to register client: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.SessionManager was not provided by any .service files

Jul 20 23:14:44 grandhuit org.a11y.atspi.Registry[1394]: ** (at-spi2-registryd:1397): WARNING **: Unable to register client with session manager

Jul 20 23:14:44 grandhuit org.gnome.zeitgeist.Engine[1308]: ** (zeitgeist-datahub:1415): WARNING **: zeitgeist-datahub.vala:226: Unable to get name "org.gnome.zeitgeist.datahub" on the bus!

Jul 20 23:14:44 grandhuit pulseaudio[1390]: Default and alternate sample rates are the same.

Jul 20 23:14:44 grandhuit pulseaudio[1390]: Default and alternate sample rates are the same.

Jul 20 23:14:44 grandhuit org.gtk.Private.AfcVolumeMonitor[1308]: Volume monitor alive

Jul 20 23:14:44 grandhuit org.gnome.OnlineAccounts[1308]: goa-daemon-Message: goa-daemon version 3.12.2 starting

/var/log/debug

Jul 20 23:09:51 grandhuit kernel: [    0.465973] pci 0000:00:02.0: Boot video device

Jul 20 23:09:51 grandhuit kernel: [    3.669446] PCI: CLS 64 bytes, default 64

Jul 20 23:09:51 grandhuit kernel: [    3.754320] pcieport 0000:00:01.0: irq 40 for MSI/MSI-X

Jul 20 23:09:51 grandhuit kernel: [    3.760999] intel_idle: MWAIT substates: 0x21120

Jul 20 23:09:51 grandhuit kernel: [    3.761000] intel_idle: v0.4 model 0x3A

Jul 20 23:09:51 grandhuit kernel: [    3.761000] intel_idle: lapic_timer_reliable_states 0xffffffff

Jul 20 23:09:51 grandhuit kernel: [    3.776696] PM: Hibernation image not present or could not be loaded.

Jul 20 23:09:51 grandhuit kernel: [    3.803229] libata version 3.00 loaded.

Jul 20 23:09:51 grandhuit kernel: [    3.803837] ahci 0000:00:1f.2: version 3.0

Jul 20 23:09:51 grandhuit kernel: [    3.803963] ahci 0000:00:1f.2: irq 41 for MSI/MSI-X

Jul 20 23:09:51 grandhuit kernel: [    4.486366] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00

Jul 20 23:09:51 grandhuit kernel: [    4.486443] sd 2:0:0:0: [sdb] Mode Sense: 00 3a 00 00

Jul 20 23:09:51 grandhuit kernel: [    6.721587] PM: Hibernation image partition 8:19 present

Jul 20 23:09:51 grandhuit kernel: [    6.721589] PM: Looking for hibernation image.

Jul 20 23:09:51 grandhuit kernel: [    6.721751] PM: Image not found (code -22)

Jul 20 23:09:51 grandhuit kernel: [    6.721753] PM: Hibernation image not present or could not be loaded.

Jul 20 23:09:51 grandhuit kernel: [    7.033188] mei_me 0000:00:16.0: irq 42 for MSI/MSI-X

Jul 20 23:09:51 grandhuit kernel: [    7.045402] ehci-pci 0000:00:1a.0: cache line size of 64 is not supported

Jul 20 23:09:51 grandhuit kernel: [    7.058511] xhci_hcd 0000:00:14.0: cache line size of 64 is not supported

Jul 20 23:09:51 grandhuit kernel: [    7.058536] xhci_hcd 0000:00:14.0: irq 43 for MSI/MSI-X

Jul 20 23:09:51 grandhuit kernel: [    7.084550] ehci-pci 0000:00:1d.0: cache line size of 64 is not supported

Jul 20 23:09:51 grandhuit kernel: [    7.097924] checking generic (e0000000 57f000) vs hw (e0000000 10000000)

Jul 20 23:09:51 grandhuit kernel: [    7.109347] ath: EEPROM regdomain: 0x65

Jul 20 23:09:51 grandhuit kernel: [    7.109348] ath: EEPROM indicates we should expect a direct regpair map

Jul 20 23:09:51 grandhuit kernel: [    7.109350] ath: Country alpha2 being used: 00

Jul 20 23:09:51 grandhuit kernel: [    7.109351] ath: Regpair used: 0x65

Jul 20 23:09:51 grandhuit kernel: [    7.138051] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'

Jul 20 23:09:51 grandhuit kernel: [    7.159617] i915 0000:00:02.0: irq 44 for MSI/MSI-X

Jul 20 23:09:51 grandhuit kernel: [    7.975833] snd_hda_intel 0000:00:1b.0: irq 45 for MSI/MSI-X

Jul 20 23:09:51 grandhuit kernel: [   14.414973] alx 0000:02:00.0: irq 46 for MSI/MSI-X

Jul 20 23:09:51 grandhuit ntpd[825]: signal_no_reset: signal 17 had flags 4000000

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully called chroot.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully dropped privileges.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully limited resources.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Running.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Canary thread running.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Watchdog thread running.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Supervising 1 threads of 1 processes of 1 users.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Supervising 2 threads of 2 processes of 1 users.

/var/log/daemon.log ==> Startup finished in 6.790s (kernel) + 1min 30.183s (userspace) = 1min 36.974s
POURQUOI on se prend 1mn30s en userspace alors que le noyau a fini en 6.79s ?????

Jul 20 23:11:13 grandhuit systemd[1]: Starting Graphical Interface.

Jul 20 23:11:13 grandhuit systemd[1]: Reached target Graphical Interface.

Jul 20 23:11:13 grandhuit systemd[1]: Starting Update UTMP about System Runlevel Changes...

Jul 20 23:11:13 grandhuit systemd[1]: Started Update UTMP about System Runlevel Changes.

Jul 20 23:11:13 grandhuit systemd[1]: Startup finished in 6.790s (kernel) + 1min 30.183s (userspace) = 1min 36.974s.

Jul 20 23:11:13 grandhuit kdm_greet[1176]: Cannot load /usr/share/kde4/apps/kdm/faces/.default.face: Aucun fichier ou dossier de ce type

Jul 20 23:14:43 grandhuit dbus[737]: [system] Activating via systemd: service name='org.freedesktop.ConsoleKit' unit='console-kit-daemon.service'

Jul 20 23:14:43 grandhuit systemd[1]: Starting Console Manager...

Jul 20 23:14:43 grandhuit console-kit-daemon[1185]: (process:1248): GLib-CRITICAL **: g_slice_set_config: assertion 'sys_page_size == 0' failed

Jul 20 23:14:43 grandhuit console-kit-daemon[1185]: missing action

Jul 20 23:14:43 grandhuit dbus[737]: [system] Successfully activated service 'org.freedesktop.ConsoleKit'

Jul 20 23:14:43 grandhuit systemd[1]: Started Console Manager.

Jul 20 23:14:43 grandhuit console-kit-daemon[1185]: (process:1257): GLib-CRITICAL **: g_slice_set_config: assertion 'sys_page_size == 0' failed

Jul 20 23:14:43 grandhuit dbus[737]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service'

Jul 20 23:14:43 grandhuit systemd[1]: Starting Disk Manager...

Jul 20 23:14:43 grandhuit udisksd[1371]: udisks daemon version 2.1.3 starting

Jul 20 23:14:44 grandhuit dbus[737]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service'

Jul 20 23:14:44 grandhuit systemd[1]: Starting RealtimeKit Scheduling Policy Service...

Jul 20 23:14:44 grandhuit dbus[737]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully called chroot.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully dropped privileges.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully limited resources.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Running.

Jul 20 23:14:44 grandhuit systemd[1]: Started RealtimeKit Scheduling Policy Service.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Canary thread running.deux

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Watchdog thread running.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully made thread 1390 of process 1390 (/usr/bin/pulseaudio) owned by '1000' high priority at nice level -11.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Supervising 1 threads of 1 processes of 1 users.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Successfully made thread 1449 of process 1449 (/usr/bin/pulseaudio) owned by '1000' high priority at nice level -11.

Jul 20 23:14:44 grandhuit rtkit-daemon[1399]: Supervising 2 threads of 2 processes of 1 users.

Jul 20 23:14:44 grandhuit systemd[1]: Starting CUPS Printing Service...

Jul 20 23:14:44 grandhuit systemd[1]: Started CUPS Printing Service.

Jul 20 23:14:44 grandhuit dbus[737]: [system] Successfully activated service 'org.freedesktop.UDisks2'

Jul 20 23:14:44 grandhuit systemd[1]: Started Disk Manager.

Jul 20 23:14:44 grandhuit udisksd[1371]: Acquired the name org.freedesktop.UDisks2 on the system message bus

Jul 20 23:22:29 grandhuit dbus[737]: [system] Activating via systemd: service name='org.freedesktop.UPower' unit='upower.service'

Jul 20 23:22:29 grandhuit systemd[1]: Starting Daemon for power management...

Jul 20 23:22:29 grandhuit dbus[737]: [system] Successfully activated service 'org.freedesktop.UPower'

Jul 20 23:22:29 grandhuit systemd[1]: Started Daemon for power management.

Jul 20 23:22:29 grandhuit systemd[1]: Starting Run anacron jobs...

Jul 20 23:22:29 grandhuit systemd[1]: Started Run anacron jobs.

Jul 20 23:24:36 grandhuit systemd[1]: Starting Cleanup of Temporary Directories...

Jul 20 23:24:36 grandhuit systemd-tmpfiles[1872]: stat(/run/user/1000/gvfs) failed: Permission denied

Jul 20 23:24:36 grandhuit systemd[1]: Started Cleanup of Temporary Directories.

Jul 20 23:32:40 grandhuit minissdpd[762]: 10 new devices added

des idées ? un bug connu ??

captnfab · 23-07-2014 07:35:45

Salut,
Alors, le problème vient très probablement de systemd qui tente d'effectuer des opérations, n'y parvient pas, et donc attend le timeout (de 30 secondes) avant de continuer.
Pour 4 minutes, ça serait probablement 7 timeouts

Une chose pouvant générer ce timeout : est-ce que tu as dans ton /etc/fstab des partitions à monter qui ne sont pas présentes au boot (genre montage usb) ? Dans ce cas as-tu bien rajouté les options noauto et/ou nofail ?

Une autre : ta config réseau est bonne ?

Sinon, je vois ce message : « Jul 20 23:24:36 grandhuit systemd-tmpfiles[1872]: stat(/run/user/1000/gvfs) failed: Permission denied » à investiguer.

grnahuit · 25-07-2014 00:07:27

Bonjour et merci !

ma config réseau est bonne.
mon /etc/fstab contient juste des montages de partitions présentes :

# /etc/fstab: static file system information.

#

# Use 'blkid' to print the universally unique identifier for a

# device; this may be used with UUID= as a more robust way to name devices

# that works even if disks are added and removed. See fstab(5).

#

# <file system> <mount point>   <type>  <options>       <dump>  <pass>

# / was on /dev/sdb2 during installation

UUID=3a9e94ec-d58d-443a-8e88-45ba24c10541 /               btrfs   defaults,ssd,noatime        0       1

# /boot/efi was on /dev/sdb1 during installation

UUID=0A76-58F8  /boot/efi       vfat    defaults        0       1

# /home was on /dev/sdb4 during installation

UUID=806d428c-f6bc-44ac-96e1-a9416bb4e623 /home           btrfs   defaults,ssd,noatime        0       2

# swap was on /dev/sdb3 during installation

UUID=455a9b4b-8133-4e65-802c-4f4a9ab32dce none            swap    sw              0       0

# fichiers temporaires et cache utilisateur en RAM

#tmpfs      /tmp            tmpfs        defaults,size=600M           0    0

#tmpfs    /home/grandhuit/.cache    tmpfs    defaults,size=600M    0    0

# logfiles en RAM

#tmpfs /var/log tmpfs defaults,nosuid,nodev,noatime,mode=0755,size=5% 0 0

le message à Jul 20 23:24:36 concerne gvfsd un daemon gnome visiblement (mais mon interface est LXDE) et cela arrive à 23:24 donc 10 mn après que je me sois connecté sous KDM
aucune trace de ce qui se passe entre 23:11 et 23:14 ....il y a bien un time-out, il faudrait que je trouve comment mettre des traces supplémentaires pour systemd ?

le démarrage dit : Startup finished in 6.790s (kernel) + 1min 30.183s (userspace) = 1min 36.974s, c'est quoi ce 1min30 passée dans le userspace et où trouver la trace de ce qu'il fait pendant ce temps ???

si il y a une daube dans KDM, je vais essayé d'installer GDM à la place et on verra ...bizarre bizarre parce que j'ai la même debian testing sur un PC desktop et le démarrage est nickel et super rapide avec systemd

Invité-5 · 25-07-2014 05:52:28

Salut, tu ne pas sans savoir que le fichiers btrfs ne gèrent pas le swap. Il est a 0(zero) d'accord, mais pourquoi as tu installé.

Je t'invite à lire => https://debian-facile.org/doc:systeme:btrfs

Dernière modification par Invité-5 (25-07-2014 06:13:07)

grnahuit · 26-07-2014 11:36:33

Salut,

oui le swap n'est pas complètement bien géré par btrfs, il l'est "à peu près"...les paramètres à 0 ne veulent pas dire que le swap est à 0, ils indiquent que la partition swap ne sera pas sauvegardée et que la vérification par fsck ne sera pas effectuée au démarrage.
je l'ai commenté dans le fstab, mais cela ne change rien. Le swap ne posait d'ailleurs pas de pb avant la dernière update de ma testing qui m'a introduit ce délai de 1mn30 au démarrage de kdm.

j'ai vu qu'il y avait un outil très sympa pour voir comment se répartissait le temps de démarrage dans les différents processus :

root@grandhuit:~# systemd-analyze critical-chain

The time after the unit is active or started is printed after the "@" character.

The time the unit takes to start is printed after the "+" character.

graphical.target @1min 30.225s

??multi-user.target @1min 30.225s

  ??kdm-gdmcompat.service @1min 30.118s +106ms

    ??kdm.service @1min 30.103s +13ms

      ??dbus.service @7.417s

        ??basic.target @7.402s

          ??sockets.target @7.402s

            ??dbus.socket @7.402s

              ??sysinit.target @7.400s

                ??nfs-common.service @7.347s +52ms

                  ??rpcbind.target @7.347s

                    ??rpcbind.service @7.321s +25ms

                      ??network.target @7.321s

                        ??networking.service @7.234s +86ms

                          ??local-fs.target @7.232s

                            ??run-rpc_pipefs.mount @7.391s

                              ??local-fs-pre.target @275ms

                                ??systemd-remount-fs.service @244ms +31ms

                                  ??keyboard-setup.service @134ms +109ms

                                    ??systemd-udevd.service @124ms +8ms

                                      ??systemd-tmpfiles-setup-dev.service @105ms +19ms

                                        ??systemd-journald.socket @103ms

                                          ??-.mount @102ms

cependant je cherche toujours un log qui me dise ce que fait ce foutu système pendant 1mn30 !!!! vu que systemd-analyze est capable de dire qu'il y a 1mn30s de bulle du système, il pourrait me dire ce qu'il fait !!!!

captnfab · 26-07-2014 12:16:28

     ??kdm.service @1min 30.103s +13ms

      ??dbus.service @7.417s

On dirait que le pb apparaît entre dbus et kdm. Mais pas de « + » affiché… Tu as essayé avec un autre DM pour voir ?

grnahuit · 26-07-2014 15:27:36

VICTOIRE !!!!!

Oui c'est bien kdm et xorg qui ramaient...à cause d'un paquet bumblebee (que j'avais installé à un moment donné) et qui est devenu cassé. J'ai viré le paquet et tout démarre dans les temps avec le nouveau systemd ultra rapide. Mais c'est vraiment dommage que kdm.log et Xorg.log ne disent rien sur ce qui se passe !!!!

c'était bien la différence entre mon desktop et mon laptop, sur le desktop il n'y a pas de bumblebee car il n'y a pas cette saloperie de technologie optimus sur les laptop qui empêche les driver nvidia de piloter directement la carte graphique...bon je vais pouvoir maintenant tester le driver nvidia et voir s'il gère bien l'optimus maintenant...nvidia dit que oui....

en tous cas, merci à tous, cela fait vraiment plaisir de trouver de l'entraide et des gens prêts à s'investir. MERCI A TOUS !!!! à bientôt

captnfab · 26-07-2014 15:42:01

\o/

Voir le tuto : C'est résolu ! Bravo mais il faut l'indiquer dans l'titre.

Et hop, un point choco

Debian-facile

#1 22-07-2014 23:30:56

après update de la testing, KDM met 4 minutes à se lancer

#2 23-07-2014 07:35:45

Re : après update de la testing, KDM met 4 minutes à se lancer

#3 25-07-2014 00:07:27

Re : après update de la testing, KDM met 4 minutes à se lancer

#4 25-07-2014 05:52:28

Re : après update de la testing, KDM met 4 minutes à se lancer

#5 26-07-2014 11:36:33

Re : après update de la testing, KDM met 4 minutes à se lancer

#6 26-07-2014 12:16:28

Re : après update de la testing, KDM met 4 minutes à se lancer

#7 26-07-2014 15:27:36

Re : après update de la testing, KDM met 4 minutes à se lancer

#8 26-07-2014 15:42:01

Re : après update de la testing, KDM met 4 minutes à se lancer

Pied de page des forums