mr-kumar-abhishek
Posts: 3
Joined: Sun Dec 18, 2016 2:13 am

Very late command prompt and logins ?

Sun Dec 18, 2016 2:32 am

Hello,
Uhm... So I have raspi 2 with me for few months now. It is working great and I was able to do some neat work in it despite its low hardware. But after few major installations such torch http://torch.ch/ and NVM https://github.com/creationix/nvm The raspi logins and command prompt are taking too much time to come up. At one point it even timed out . I am not keeping x active so I login from the console. I figured there must have been something wrong in .bashrc file , but if it is that , then why does even root takes a long time to log in ?

Any help is appreciated. And thanks in advance. If there are any more information that might be useful to solve this problem that I am missing to put here then please ask.

peterlite
Posts: 720
Joined: Sun Apr 17, 2016 4:00 am

Re: Very late command prompt and logins ?

Sun Dec 18, 2016 6:32 am

Look through /var/log/syslog for errors and network problems. A slow startup is either applications doing millions of things on a slow microSD card or a network connection timeout or errors.

mr-kumar-abhishek
Posts: 3
Joined: Sun Dec 18, 2016 2:13 am

Re: Very late command prompt and logins ?

Sun Dec 18, 2016 11:22 am

I have gone through the syslog as suggested . Everything looks good at the end , but I need to ask about some things that I found in the start. Such as bus connections is not being made.

Code: Select all

Dec 18 07:17:01 ql CRON[32550]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Dec 18 07:21:56 ql org.gtk.vfs.Daemon[9365]: A connection to the bus can't be made
Dec 18 07:21:56 ql org.gtk.vfs.Daemon[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 
bytes on an async read (g-io-error-quark, 0). Exiting.
Dec 18 07:21:56 ql org.gtk.Private.AfcVolumeMonitor[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStre
am returned 0 bytes on an async read (g-io-error-quark, 0). Exiting.
Dec 18 07:21:56 ql org.gtk.Private.GoaVolumeMonitor[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStre
am returned 0 bytes on an async read (g-io-error-quark, 0). Exiting.
Dec 18 07:21:56 ql org.gtk.Private.GPhoto2VolumeMonitor[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIO
Stream returned 0 bytes on an async read (g-io-error-quark, 0). Exiting.
Dec 18 07:21:56 ql org.gtk.Private.MTPVolumeMonitor[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Error sending mess
age: Broken pipe (g-io-error-quark, 44). Exiting.
Dec 18 07:21:56 ql org.gtk.vfs.Daemon[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 
bytes on an async read (g-io-error-quark, 0). Exiting.
Dec 18 07:21:56 ql org.gtk.Private.UDisks2VolumeMonitor[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Error sending 
message: Broken pipe (g-io-error-quark, 44). Exiting.
Dec 18 07:21:57 ql org.gtk.vfs.Daemon[9365]: A connection to the bus can't be made
Dec 18 07:21:57 ql org.gtk.vfs.Daemon[9365]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 
bytes on an async read (g-io-error-quark, 0). Exiting.
Dec 18 07:22:03 ql systemd[1]: Started Synchronise Hardware Clock to System Clock.


Then there is failure in mtp probe.

Code: Select all

Dec 18 07:22:13 ql systemd-udevd[187]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5 1 6': No such file or directory

Code: Select all

Dec 18 07:22:13 ql systemd-udevd[221]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1 1 3': No such file or directory
Dec 18 07:22:13 ql systemd-udevd[223]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3 1 5': No such file or directory

After this.... host name of debian.pool.ntp.org is not found ( do I even need these ? )

Code: Select all

Dec 18 07:22:16 ql systemd[1]: Started LSB: An object/document-oriented database.
Dec 18 07:22:16 ql ntpd_intres[568]: host name not found: 0.debian.pool.ntp.org
Dec 18 07:22:16 ql ntpd_intres[568]: host name not found: 1.debian.pool.ntp.org
Dec 18 07:22:16 ql ntpd_intres[568]: host name not found: 2.debian.pool.ntp.org
Dec 18 07:22:16 ql ntpd_intres[568]: host name not found: 3.debian.pool.ntp.org
Then there was a `action 17` suspension

Code: Select all

Dec 18 07:27:00 ql systemd[1]: Stopping Login Prompts.
Dec 18 07:27:00 ql rsyslogd-2007: action 'action 17' suspended, next retry is Sun Dec 18 07:27:30 2016 [try http://www.rsyslog.com/e/2007 ]

bounce in buffers:

Code: Select all

Dec 18 07:27:08 ql kernel: [    2.405103] Dedicated Tx FIFOs mode
Dec 18 07:27:08 ql kernel: [    2.409192] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xbac14000 dma = 0xfac14000 len=9024
Dec 18 07:27:08 ql kernel: [    2.419370] FIQ FSM acceleration enabled for :

some hostnames not found again , I am not sure what other texts mean though.

Code: Select all

Dec 18 07:27:11 ql ntpd_intres[598]: host name not found: 0.debian.pool.ntp.org
Dec 18 07:27:11 ql ntpd_intres[598]: host name not found: 1.debian.pool.ntp.org
Dec 18 07:27:11 ql ntpd_intres[598]: host name not found: 2.debian.pool.ntp.org
Dec 18 07:27:11 ql ntpd_intres[598]: host name not found: 3.debian.pool.ntp.org
^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@Dec 18 07:27:08 qaz rsyslogd: [origin software="rsyslogd" swVersion="8.4.2" x-pid="470" x-info="http://www.rsyslog.com"] start

failure in mtp probe again ... (should I disconnect this device all together ? )

Code: Select all

Dec 18 07:27:08 ql systemd-udevd[205]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1
.1 1 3': No such file or directory
Dec 18 07:27:08 ql kernel: [    0.000000] PERCPU: Embedded 13 pages/cpu @b9f62000 s22592 r8192 d22464 u53248
Dec 18 07:27:08 ql systemd-udevd[206]: failed to execute '/lib/udev/mtp-probe' 'mtp-probe /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1
.5 1 4': No such file or directory






warning of bouncing buffers again :

Code: Select all

Dec 18 07:27:08 ql kernel: [    2.412012] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xbac14000 dma = 0xfac14000 len=9024


Some other warnings:

Code: Select all

Dec 18 07:27:08 ql kernel: [    2.445293] WARN::hcd_init_fiq:413: FIQ on core 1 at 0x8044846c
Dec 18 07:27:08 ql dhcpcd[395]: forked to background, child pid 420
Dec 18 07:27:08 ql kernel: [    2.451407] WARN::hcd_init_fiq:414: FIQ ASM at 0x804487dc length 36
Dec 18 07:27:08 ql kernel: [    2.457873] WARN::hcd_init_fiq:439: MPHI regs_base at 0xbb87e000


hostnames not found again (I really don't connect to internet while bootups)

Code: Select all

Dec 18 07:27:54 ql systemd[1]: Started User Manager for UID 1000.
Dec 18 07:28:13 ql ntpd_intres[543]: host name not found: 0.debian.pool.ntp.org
Dec 18 07:28:13 ql ntpd_intres[543]: host name not found: 1.debian.pool.ntp.org
Dec 18 07:28:13 ql ntpd_intres[543]: host name not found: 2.debian.pool.ntp.org
Dec 18 07:28:13 ql ntpd_intres[543]: host name not found: 3.debian.pool.ntp.org


I don't want this bluetooth daemon running I don't have bluetooth hardware. So what should I do about this ?

Code: Select all

ec 18 07:32:09 ql systemd[1]: Starting Bluetooth service...
Dec 18 07:32:09 ql bluetoothd[2360]: Bluetooth daemon 5.23

another this is ... SD card is connected but I still get this:

Code: Select all

Dec 18 07:32:08 ql udisksd[2320]: Cleaning up mount point /media/pi/SETTINGS1 (device 179:5 is not mounted)

I don't want these bluetooth services running , how stop them ?

Code: Select all

Dec 18 07:32:09 ql systemd[1]: Starting Bluetooth service...
Dec 18 07:32:09 ql bluetoothd[2360]: Bluetooth daemon 5.23
Dec 18 07:32:09 ql dbus[403]: [system] Successfully activated service 'org.bluez'
Dec 18 07:32:09 ql rsyslogd-2007: action 'action 17' suspended, next retry is Sun Dec 18 07:32:39 2016 [try http://www.rsyslog.com/e/2007 ]
Dec 18 07:32:09 ql systemd[1]: Started Bluetooth service.
Dec 18 07:32:09 ql bluetoothd[2360]: Starting SDP server
Dec 18 07:32:09 ql kernel: [  327.886283] Bluetooth: Core ver 2.21
Dec 18 07:32:09 ql kernel: [  327.886431] NET: Registered protocol family 31
Dec 18 07:32:09 ql kernel: [  327.886444] Bluetooth: HCI device and connection manager initialized
Dec 18 07:32:09 ql kernel: [  327.886483] Bluetooth: HCI socket layer initialized
Dec 18 07:32:09 ql kernel: [  327.886507] Bluetooth: L2CAP socket layer initialized
Dec 18 07:32:09 ql kernel: [  327.886558] Bluetooth: SCO socket layer initialized
Dec 18 07:32:09 ql kernel: [  327.956359] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Dec 18 07:32:09 ql kernel: [  327.956389] Bluetooth: BNEP filters: protocol multicast
Dec 18 07:32:09 ql kernel: [  327.956426] Bluetooth: BNEP socket layer initialized
Dec 18 07:32:09 ql dbus[403]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service'
Dec 18 07:32:09 ql bluetoothd[2360]: Bluetooth management interface 1.10 initialized
Dec 18 07:32:09 ql pulseaudio[2331]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist
Dec 18 07:32:09 ql pulseaudio[2331]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist
I don't know what I am missing here, please suggest what to do.

Code: Select all

Dec 18 07:32:09 ql systemd[1]: Starting Hostname Service...
Dec 18 07:32:12 ql systemd-hostnamed[2368]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname!

Few hostnames not found again

Code: Select all

Dec 18 07:33:45 ql ntpd[533]: peers refreshed
Dec 18 07:33:47 ql ntpd_intres[543]: host name not found: 0.debian.pool.ntp.org
Dec 18 07:33:47 ql ntpd_intres[543]: host name not found: 1.debian.pool.ntp.org
Dec 18 07:33:47 ql ntpd_intres[543]: host name not found: 2.debian.pool.ntp.org
Dec 18 07:33:47 ql ntpd_intres[543]: host name not found: 3.debian.pool.ntp.org

Again suspension of action 17

Code: Select all

Dec 18 07:37:32 ql rsyslogd-2007: action 'action 17' suspended, next retry is Sun Dec 18 07:38:02 2016 [try http://www.rsyslog.com/e/2007 ]
Dec 18 07:38:58 ql rsyslogd-2007: action 'action 17' suspended, next retry is Sun Dec 18 07:39:28 2016 [try http://www.rsyslog.com/e/2007 ]

what to do with this ?

Code: Select all

Dec 18 08:11:39 ql kbd[256]: setterm: $TERM is not defined.

and what to do with these warnings ?

Code: Select all

Dec 18 08:11:39 ql kernel: [    2.406849] Interrupt/Control Split Transaction hack enabled
Dec 18 08:11:39 ql kernel: [    2.429869] dwc_otg: Microframe scheduler enabled
Dec 18 08:11:39 ql kernel: [    2.429952] WARN::hcd_init_fiq:413: FIQ on core 1 at 0x8044846c
Dec 18 08:11:39 ql kernel: [    2.436062] WARN::hcd_init_fiq:414: FIQ ASM at 0x804487dc length 36
Dec 18 08:11:39 ql kernel: [    2.442524] WARN::hcd_init_fiq:439: MPHI regs_base at 0xbb87e000

Should I turn some service off regarding this ?

Code: Select all

Dec 18 08:11:40 ql dhcpcd[422]: eth0: waiting for carrier
Dec 18 08:11:40 ql kernel: [   11.120951] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup

And that sums it up more or less. Any inputs is appreciated

epoch1970
Posts: 5203
Joined: Thu May 05, 2016 9:33 am
Location: Paris, France

Re: Very late command prompt and logins ?

Sun Dec 18, 2016 12:39 pm

eth0 (still) waiting for carrier and (consequently?) dhclient having given up sure don't look good...
"S'il n'y a pas de solution, c'est qu'il n'y a pas de problème." Les Shadoks, J. Rouxel

peterlite
Posts: 720
Joined: Sun Apr 17, 2016 4:00 am

Re: Very late command prompt and logins ?

Mon Dec 19, 2016 8:12 pm

If eth0 is not connected, you will get some of the other messages such as NTP servers not found. Network checks can have long timeouts.

Return to “Beginners”