maisen
Posts: 2
Joined: Fri Jul 05, 2019 7:36 pm

Wondershare SIM7600E 4G HAT internet connection only after reboot or restart service

Wed Mar 11, 2020 9:12 am

Hello everybody

Here's my problem:
My 4G HAT is having a lot of trouble connecting. The internet connection is only successfully established after service restart or reboot. This means that if I turn off my Raspberry Pi 3 B+ completely, then connect to the power again and it starts up, my 4G HAT cannot connect. If I then type "sudo reboot now", my Pi will reboot and after that the internet connection is successfully connected.

Infos:
  • Raspberry Pi 3 B+
  • Connected to my network via LAN
  • After first boot not working, but after service restart or second (or more) reboot it's working
A workaround would be to restart the service when it fails. But at the moment, the service will not restart because it does not detect the failed wwan0 configuration in my ltestartup script. How could i detect the failed configuration in ltestartup and tell my service that its failed?

Here my Service:

Code: Select all

 [Unit]
 Description=4G LTE HAT autostart after boot
 After=multi-user.target

 [Service]
 Type=idle
 ExecStart=/bin/bash /home/pi/ltestartup

 [Install]
 WantedBy=multi-user.target

Here my ltestartup bash script:

Code: Select all

#!/bin/bash

exec &> /home/pi/lte_startup.log

PWD='password'
defaultDelay=180

if [ -z "$1" ]
then
	delay=$defaultDelay
else
	delay="$1"
fi

if [ $delay -gt 60 ]
then
	delayMIN=$((delay / 60))
	delayTXT=${delayMIN}'min'
else
	delayTXT=$delay's'
fi

msg=$(date +"%D %T")"
Wait ${delayTXT} and then starting LTE HAT and internet connection... "
echo $msg

(

	# if file exists, use 4G HAT for internetconnection
	if [ -f /boot/ltestart ]; then
		sleep $delay

		msg=$(date +"%D %T")"
		${delayTXT} elapsed, starting LTE connection..."
		echo $msg

		echo $PWD | sudo -S qmicli -d /dev/cdc-wdm0 --dms-set-operating-mode='online'
		sudo qmicli -d /dev/cdc-wdm0 --dms-get-operating-mode
		sudo qmicli -d /dev/cdc-wdm0 --nas-get-signal-strength
		sudo qmicli -d /dev/cdc-wdm0 --nas-get-home-network
		sudo qmicli -d /dev/cdc-wdm0 -w
		sudo ip link set wwan0 down
		echo 'Y' | sudo tee /sys/class/net/wwan0/qmi/raw_ip
		sudo ip link set wwan0 up
		sudo qmicli -p -d /dev/cdc-wdm0 --device-open-net='net-raw-ip|net-no-qos-header' --wds-start-network="apn='MY CORRECT APN',ip-type=4" --client-no-release-cid
		sudo udhcpc -i wwan0

		# Get IP of the Raspberry
		IP=$(curl https://ip.myOwnDomainToGetTheIP.com)

		msg=$(date +"%D %T")"
		<b>Raspberry Pi is online</b>.
		IP-Adress: ${IP}"
		echo $msg

		python /home/pi/Telegram/sendMessage.py "$msg"


	fi

) 


Here the syslog:

Code: Select all

Mar 11 09:55:15 raspberrypi systemd[1]: Starting Check for Raspberry Pi EEPROM updates...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting WPA supplicant...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Mar 11 09:55:15 raspberrypi systemd[1]: Started Daily Cleanup of Temporary Directories.
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Login Service...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting System Logging Service...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting triggerhappy global hotkey daemon...
Mar 11 09:55:15 raspberrypi systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Check for v3d driver...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting rng-tools.service...
Mar 11 09:55:15 raspberrypi systemd[1]: Reached target System Time Synchronized.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Daily apt download activities.
Mar 11 09:55:15 raspberrypi udisksd[312]: udisks daemon version 2.8.1 starting
Mar 11 09:55:15 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Daily man-db regeneration.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Daily rotation of log files.
Mar 11 09:55:15 raspberrypi systemd[1]: Reached target Timers.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Mar 11 09:55:15 raspberrypi systemd[1]: Reached target Sound Card.
Mar 11 09:55:15 raspberrypi dhcpcd[319]: dev: loaded udev
Mar 11 09:55:15 raspberrypi rng-tools[360]: Starting Hardware RNG entropy gatherer daemon: rngd.
Mar 11 09:55:15 raspberrypi rngd[373]: rngd 2-unofficial-mt.14 starting up...
Mar 11 09:55:15 raspberrypi rngd[373]: entropy feed to the kernel ready
Mar 11 09:55:15 raspberrypi thd[348]: Found socket passed from systemd
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113).
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: Successfully dropped root privileges.
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: avahi-daemon 0.7 starting up.
Mar 11 09:55:15 raspberrypi dphys-swapfile[316]: want /var/swap=100MByte, checking existing: keeping it
Mar 11 09:55:15 raspberrypi rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.1901.0]
Mar 11 09:55:15 raspberrypi rsyslogd:  [origin software="rsyslogd" swVersion="8.1901.0" x-pid="340" x-info="https://www.rsyslog.com"] start
Mar 11 09:55:15 raspberrypi dhcpcd[319]: forked to background, child pid 390
Mar 11 09:55:15 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Mar 11 09:55:15 raspberrypi systemd[1]: Started System Logging Service.
Mar 11 09:55:15 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: Successfully called chroot().
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: Successfully dropped remaining capabilities.
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: No service file found in /etc/avahi/services.
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: Network interface enumeration completed.
Mar 11 09:55:15 raspberrypi avahi-daemon[330]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 1875631311.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Check for v3d driver.
Mar 11 09:55:15 raspberrypi systemd[1]: Started rng-tools.service.
Mar 11 09:55:15 raspberrypi wpa_supplicant[329]: Successfully initialized wpa_supplicant
Mar 11 09:55:15 raspberrypi udisksd[312]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory
Mar 11 09:55:15 raspberrypi udisksd[312]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory
Mar 11 09:55:15 raspberrypi systemd[1]: Started Login Service.
Mar 11 09:55:15 raspberrypi udisksd[312]: Failed to load the 'mdraid' libblockdev plugin
Mar 11 09:55:15 raspberrypi udisksd[312]: Failed to load the 'crypto' libblockdev plugin
Mar 11 09:55:15 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Mar 11 09:55:15 raspberrypi dbus-daemon[315]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=312 comm="/usr/lib/udisks2/udisksd ")
Mar 11 09:55:15 raspberrypi systemd[1]: Started WPA supplicant.
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Authorization Manager...
Mar 11 09:55:15 raspberrypi systemd[1]: Reached target Network.
Mar 11 09:55:15 raspberrypi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Mar 11 09:55:15 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Mar 11 09:55:15 raspberrypi kernel: [    7.812468] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Permit User Sessions...
Mar 11 09:55:15 raspberrypi raspi-config[323]: Checking if shift key is held down:Error opening '/dev/input/event*': No such file or directory
Mar 11 09:55:15 raspberrypi systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file.
Mar 11 09:55:15 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Mar 11 09:55:15 raspberrypi raspi-config[323]:  No. Switching to ondemand scaling governor.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Remote tcp command service.
Mar 11 09:55:15 raspberrypi systemd[1]: Started Remote tcp connection service.
Mar 11 09:55:15 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Mar 11 09:55:15 raspberrypi systemd[1]: Started Permit User Sessions.
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
Mar 11 09:55:15 raspberrypi systemd[1]: Starting Light Display Manager...
Mar 11 09:55:15 raspberrypi connectd_schannel[426]: remote.it server channel daemon start/stop script Version: 2.4.26
Mar 11 09:55:16 raspberrypi root: [connectd_start] Startup
Mar 11 09:55:16 raspberrypi dhcpcd-run-hooks[454]: wlan0: starting wpa_supplicant
Mar 11 09:55:16 raspberrypi connectd_schannel[426]: Starting connectd_schannel.arm-linaro-pi...
Mar 11 09:55:16 raspberrypi connectd_schannel[426]: server_channel_handler built Jan  7 2019 at 16:56:32
Mar 11 09:55:16 raspberrypi connectd_schannel[426]:    Version 0.5 -  (c)2019 remot3.it, Inc. All Rights Reserved
Mar 11 09:55:16 raspberrypi server_channel[460]: Server Channel built Jan  7 2019 at 16:56:32
Mar 11 09:55:16 raspberrypi server_channel[460]:    Version 0.5 -  (c)2019 remot3.it, Inc. All Rights Reserved
Mar 11 09:55:16 raspberrypi connectd_schannel[426]: Starting up as daemon
Mar 11 09:55:16 raspberrypi server_channel[460]: Starting up as daemon
Mar 11 09:55:16 raspberrypi connectd_schannel[426]: Starting up as daemon
Mar 11 09:55:16 raspberrypi server_channel[460]: Bound to UDP 127.0.0.1:5980 on socket 3
Mar 11 09:55:16 raspberrypi connectd_schannel[426]: Starting up as daemon
Mar 11 09:55:16 raspberrypi server_channel[463]: close std fds / failed: Success
Mar 11 09:55:16 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wlan0: connected to Access Point `'
Mar 11 09:55:16 raspberrypi dhcpcd[390]: eth0: waiting for carrier
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wwan0: waiting for carrier
Mar 11 09:55:16 raspberrypi dhcpcd[390]: dhcpcd_prestartinterface: wlan0: Operation not possible due to RF-kill
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wlan0: waiting for carrier
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wwan0: carrier acquired
Mar 11 09:55:16 raspberrypi kernel: [    8.292962] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Mar 11 09:55:16 raspberrypi kernel: [    8.292978] 8021q: adding VLAN 0 to HW filter on device eth0
Mar 11 09:55:16 raspberrypi kernel: [    8.307115] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Mar 11 09:55:16 raspberrypi dhcpcd[390]: DUID 00:01:00:01:25:d8:32:e8:b8:27:eb:2b:8d:08
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wwan0: IAID 73:08:cf:45
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wwan0: adding address fe80::3259:585c:8645:cb10
Mar 11 09:55:16 raspberrypi avahi-daemon[330]: Joining mDNS multicast group on interface wwan0.IPv6 with address fe80::3259:585c:8645:cb10.
Mar 11 09:55:16 raspberrypi avahi-daemon[330]: New relevant interface wwan0.IPv6 for mDNS.
Mar 11 09:55:16 raspberrypi avahi-daemon[330]: Registering new address record for fe80::3259:585c:8645:cb10 on wwan0.*.
Mar 11 09:55:16 raspberrypi dhcpcd[390]: eth0: carrier acquired
Mar 11 09:55:16 raspberrypi dhcpcd[390]: eth0: IAID eb:27:58:19
Mar 11 09:55:16 raspberrypi dhcpcd[390]: eth0: adding address fe80::6b8e:d5f:8e67:edcd
Mar 11 09:55:16 raspberrypi avahi-daemon[330]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::6b8e:d5f:8e67:edcd.
Mar 11 09:55:16 raspberrypi avahi-daemon[330]: New relevant interface eth0.IPv6 for mDNS.
Mar 11 09:55:16 raspberrypi avahi-daemon[330]: Registering new address record for fe80::6b8e:d5f:8e67:edcd on eth0.*.
Mar 11 09:55:16 raspberrypi lightdm[447]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Mar 11 09:55:16 raspberrypi polkitd[410]: started daemon version 0.105 using authority implementation `local' version `0.105'
Mar 11 09:55:16 raspberrypi dbus-daemon[315]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Mar 11 09:55:16 raspberrypi systemd[1]: Started Authorization Manager.
Mar 11 09:55:16 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 155 (plymouthd).
Mar 11 09:55:16 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 155 (plymouthd).
Mar 11 09:55:16 raspberrypi systemd[1]: plymouth-quit-wait.service: Succeeded.
Mar 11 09:55:16 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Mar 11 09:55:16 raspberrypi systemd[1]: Started Getty on tty1.
Mar 11 09:55:16 raspberrypi systemd[1]: Reached target Login Prompts.
Mar 11 09:55:16 raspberrypi systemd[1]: plymouth-start.service: Succeeded.
Mar 11 09:55:16 raspberrypi systemd[1]: Started Light Display Manager.
Mar 11 09:55:16 raspberrypi systemd[1]: Started Disk Manager.
Mar 11 09:55:16 raspberrypi udisksd[312]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Mar 11 09:55:16 raspberrypi dhcpcd[390]: wwan0: soliciting an IPv6 router
Mar 11 09:55:16 raspberrypi dhcpcd[390]: eth0: soliciting an IPv6 router
Mar 11 09:55:17 raspberrypi dhcpcd[390]: wwan0: soliciting a DHCP lease
Mar 11 09:55:17 raspberrypi dhcpcd[390]: eth0: rebinding lease of 192.168.184.25
Mar 11 09:55:17 raspberrypi dhcpcd[390]: eth0: probing address 192.168.184.25/24
Mar 11 09:55:18 raspberrypi lightdm[508]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Mar 11 09:55:18 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Mar 11 09:55:18 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Mar 11 09:55:18 raspberrypi systemd[1]: Started User Runtime Directory /run/user/1000.
Mar 11 09:55:18 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Mar 11 09:55:18 raspberrypi systemd[516]: Reached target Paths.
Mar 11 09:55:18 raspberrypi systemd[516]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Mar 11 09:55:18 raspberrypi systemd[516]: Starting D-Bus User Message Bus Socket.
Mar 11 09:55:18 raspberrypi systemd[516]: Reached target Timers.
Mar 11 09:55:18 raspberrypi systemd[516]: Listening on GnuPG network certificate management daemon.
Mar 11 09:55:18 raspberrypi systemd[516]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Mar 11 09:55:18 raspberrypi systemd[516]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Mar 11 09:55:18 raspberrypi systemd[516]: Listening on GnuPG cryptographic agent and passphrase cache.
Mar 11 09:55:18 raspberrypi systemd[516]: Listening on D-Bus User Message Bus Socket.
Mar 11 09:55:18 raspberrypi systemd[516]: Reached target Sockets.
Mar 11 09:55:18 raspberrypi systemd[516]: Reached target Basic System.
Mar 11 09:55:18 raspberrypi systemd[516]: Reached target Default.
Mar 11 09:55:18 raspberrypi systemd[516]: Startup finished in 280ms.
Mar 11 09:55:18 raspberrypi systemd[1]: Started User Manager for UID 1000.
Mar 11 09:55:18 raspberrypi systemd[1]: Started Session c1 of user pi.
Mar 11 09:55:19 raspberrypi lightdm[447]: Error opening audit socket: Protocol not supported
Mar 11 09:55:19 raspberrypi systemd[516]: Started D-Bus User Message Bus.
Mar 11 09:55:19 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Mar 11 09:55:20 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=1000 pid=530 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE ")
Mar 11 09:55:20 raspberrypi systemd[516]: Starting Virtual filesystem service...
Mar 11 09:55:20 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Successfully activated service 'org.gtk.vfs.Daemon'
Mar 11 09:55:20 raspberrypi systemd[516]: Started Virtual filesystem service.
Mar 11 09:55:20 raspberrypi kernel: [   12.519284] fuse init (API version 7.27)
Mar 11 09:55:20 raspberrypi systemd[1]: Mounting FUSE Control File System...
Mar 11 09:55:20 raspberrypi systemd[1]: Mounted FUSE Control File System.
Mar 11 09:55:21 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=597 comm="pcmanfm --desktop --profile LXDE-pi ")
Mar 11 09:55:21 raspberrypi systemd[516]: Starting Virtual filesystem service - disk device monitor...
Mar 11 09:55:21 raspberrypi systemd[1]: Started Session c2 of user pi.
Mar 11 09:55:21 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Mar 11 09:55:21 raspberrypi systemd[516]: Started Virtual filesystem service - disk device monitor.
Mar 11 09:55:21 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.7' (uid=1000 pid=597 comm="pcmanfm --desktop --profile LXDE-pi ")
Mar 11 09:55:21 raspberrypi systemd[516]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Mar 11 09:55:21 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Mar 11 09:55:21 raspberrypi systemd[516]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Mar 11 09:55:21 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.7' (uid=1000 pid=597 comm="pcmanfm --desktop --profile LXDE-pi ")
Mar 11 09:55:21 raspberrypi systemd[516]: Starting Virtual filesystem service - Apple File Conduit monitor...
Mar 11 09:55:21 raspberrypi gvfs-afc-volume-monitor[687]: Volume monitor alive
Mar 11 09:55:22 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Mar 11 09:55:22 raspberrypi systemd[516]: Started Virtual filesystem service - Apple File Conduit monitor.
Mar 11 09:55:22 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.7' (uid=1000 pid=597 comm="pcmanfm --desktop --profile LXDE-pi ")
Mar 11 09:55:22 raspberrypi systemd[516]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Mar 11 09:55:22 raspberrypi dhcpcd[390]: eth0: leased 192.168.184.25 for 864000 seconds
Mar 11 09:55:22 raspberrypi avahi-daemon[330]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.184.25.
Mar 11 09:55:22 raspberrypi avahi-daemon[330]: New relevant interface eth0.IPv4 for mDNS.
Mar 11 09:55:22 raspberrypi avahi-daemon[330]: Registering new address record for 192.168.184.25 on eth0.IPv4.
Mar 11 09:55:22 raspberrypi dhcpcd[390]: eth0: adding route to 192.168.184.0/24
Mar 11 09:55:22 raspberrypi dhcpcd[390]: eth0: adding default route via 192.168.184.1
Mar 11 09:55:22 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Mar 11 09:55:22 raspberrypi systemd[516]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Mar 11 09:55:22 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.7' (uid=1000 pid=597 comm="pcmanfm --desktop --profile LXDE-pi ")
Mar 11 09:55:22 raspberrypi systemd[516]: Starting Virtual filesystem service - digital camera monitor...
Mar 11 09:55:22 raspberrypi kernel: [   14.094338] Bluetooth: Core ver 2.22
Mar 11 09:55:22 raspberrypi kernel: [   14.094466] NET: Registered protocol family 31
Mar 11 09:55:22 raspberrypi kernel: [   14.094469] Bluetooth: HCI device and connection manager initialized
Mar 11 09:55:22 raspberrypi kernel: [   14.096483] Bluetooth: HCI socket layer initialized
Mar 11 09:55:22 raspberrypi kernel: [   14.096499] Bluetooth: L2CAP socket layer initialized
Mar 11 09:55:22 raspberrypi kernel: [   14.096540] Bluetooth: SCO socket layer initialized
Mar 11 09:55:22 raspberrypi kernel: [   14.119859] Bluetooth: HCI UART driver ver 2.3
Mar 11 09:55:22 raspberrypi kernel: [   14.119874] Bluetooth: HCI UART protocol H4 registered
Mar 11 09:55:22 raspberrypi kernel: [   14.120616] Bluetooth: HCI UART protocol Three-wire (H5) registered
Mar 11 09:55:22 raspberrypi kernel: [   14.120808] Bluetooth: HCI UART protocol Broadcom registered
Mar 11 09:55:22 raspberrypi btuart[317]: bcm43xx_init
Mar 11 09:55:22 raspberrypi btuart[317]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd
Mar 11 09:55:22 raspberrypi btuart[317]: Set BDADDR UART: b8:27:eb:8d:f2:b3
Mar 11 09:55:22 raspberrypi btuart[317]: Set Controller UART speed to 3000000 bit/s
Mar 11 09:55:22 raspberrypi btuart[317]: Device setup complete
Mar 11 09:55:22 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Mar 11 09:55:22 raspberrypi dbus-daemon[539]: [session uid=1000 pid=539] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Mar 11 09:55:22 raspberrypi systemd[516]: Started Virtual filesystem service - digital camera monitor.
Mar 11 09:55:22 raspberrypi systemd[1]: Created slice system-bthelper.slice.
Mar 11 09:55:22 raspberrypi systemd[1]: Starting Bluetooth service...
Mar 11 09:55:22 raspberrypi systemd[1]: Reached target Multi-User System.
Mar 11 09:55:22 raspberrypi systemd[1]: Started 4G LTE HAT autostart after boot.
Mar 11 09:55:22 raspberrypi systemd[1]: Reached target Graphical Interface.
Mar 11 09:55:22 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Mar 11 09:55:22 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Mar 11 09:55:22 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Mar 11 09:55:22 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Mar 11 09:55:22 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Mar 11 09:55:22 raspberrypi dhcpcd[390]: wwan0: probing for an IPv4LL address
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Bluetooth daemon 5.50
Mar 11 09:55:22 raspberrypi systemd[1]: Started Bluetooth service.
Mar 11 09:55:22 raspberrypi systemd[1]: Started Raspberry Pi bluetooth helper.
Mar 11 09:55:22 raspberrypi systemd[1]: Started BluezALSA proxy.
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Starting SDP server
Mar 11 09:55:22 raspberrypi systemd[1]: Reached target Bluetooth.
Mar 11 09:55:22 raspberrypi systemd[1]: Startup finished in 1.536s (kernel) + 12.890s (userspace) = 14.427s.
Mar 11 09:55:22 raspberrypi systemd[1]: bthelper@hci0.service: Succeeded.
Mar 11 09:55:22 raspberrypi dbus-daemon[315]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.17' (uid=0 pid=758 comm="/usr/lib/bluetooth/bluetoothd ")
Mar 11 09:55:22 raspberrypi kernel: [   14.477278] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Mar 11 09:55:22 raspberrypi kernel: [   14.477289] Bluetooth: BNEP filters: protocol multicast
Mar 11 09:55:22 raspberrypi kernel: [   14.477306] Bluetooth: BNEP socket layer initialized
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Bluetooth management interface 1.14 initialized
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Sap driver initialization failed.
Mar 11 09:55:22 raspberrypi bluetoothd[758]: sap-server: Operation not permitted (1)
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Endpoint registered: sender=:1.18 path=/org/bluez/hci0/A2DP/SBC/Source/1
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Endpoint registered: sender=:1.18 path=/org/bluez/hci0/A2DP/SBC/Source/2
Mar 11 09:55:22 raspberrypi systemd[1]: Starting Hostname Service...
Mar 11 09:55:22 raspberrypi kernel: [   14.532776] Bluetooth: RFCOMM TTY layer initialized
Mar 11 09:55:22 raspberrypi kernel: [   14.532813] Bluetooth: RFCOMM socket layer initialized
Mar 11 09:55:22 raspberrypi kernel: [   14.532837] Bluetooth: RFCOMM ver 1.11
Mar 11 09:55:22 raspberrypi bluetoothd[758]: Failed to set privacy: Rejected (0x0b)
Mar 11 09:55:22 raspberrypi dbus-daemon[315]: [system] Successfully activated service 'org.freedesktop.hostname1'
Mar 11 09:55:22 raspberrypi systemd[1]: Started Hostname Service.
Mar 11 09:55:27 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Mar 11 09:55:27 raspberrypi dhcpcd[390]: wwan0: using IPv4LL address 169.254.23.65
Mar 11 09:55:27 raspberrypi dhcpcd[390]: wwan0: adding route to 169.254.0.0/16
Mar 11 09:55:27 raspberrypi avahi-daemon[330]: Joining mDNS multicast group on interface wwan0.IPv4 with address 169.254.23.65.
Mar 11 09:55:27 raspberrypi avahi-daemon[330]: New relevant interface wwan0.IPv4 for mDNS.
Mar 11 09:55:27 raspberrypi avahi-daemon[330]: Registering new address record for 169.254.23.65 on wwan0.IPv4.
Mar 11 09:55:29 raspberrypi dhcpcd[390]: eth0: no IPv6 Routers available
Mar 11 09:55:30 raspberrypi dhcpcd[390]: wwan0: no IPv6 Routers available
Mar 11 09:55:31 raspberrypi root: [connectd_start] Loop
Mar 11 09:55:35 raspberrypi root: [] Startup
Mar 11 09:55:36 raspberrypi root: /usr/bin/connectd_start_all started: 
Mar 11 09:55:36 raspberrypi connectd_start[427]: Connectd daemon start/stop script Version: 2.4.26
Mar 11 09:55:36 raspberrypi connectd_start[427]: Starting Connectdrmt365535...
Mar 11 09:55:36 raspberrypi Connectd[921]: Connectd Target built Apr 19 2019 at 16:45:30
Mar 11 09:55:36 raspberrypi Connectd[921]:    Version 4.6 - (c)2019 remot3.it, Inc. All Rights Reserved
Mar 11 09:55:36 raspberrypi Connectd[921]: Starting up as daemon
Mar 11 09:55:36 raspberrypi Connectd[921]: Parent Exited Normally.
Mar 11 09:55:36 raspberrypi Connectd[922]: Begin Startup.
Mar 11 09:55:36 raspberrypi Connectd[923]: Creating pidfile /var/run/Connectdrmt365535.pid with PID 923
Mar 11 09:55:36 raspberrypi connectd_start[427]: Connectd built Apr 19 2019 at 16:45:30 Now Starting Up
Mar 11 09:55:36 raspberrypi connectd_start[427]:    Version 4.6 - (c)2019 remot3.it, Inc. All Rights Reserved
Mar 11 09:55:36 raspberrypi connectd_start[427]:    Built with ALIGN BCASTER MALLOC_POOL LINUX RESOLVE BIGBUF BACKTRACE pool=524288
Mar 11 09:55:36 raspberrypi connectd_start[427]:    Raspberry Pi Version
Mar 11 09:55:36 raspberrypi connectd_start[427]: config file //etc/connectd/services/Connectdrmt365535.conf
Mar 11 09:55:36 raspberrypi connectd_start[427]: Starting up as daemon
Mar 11 09:55:36 raspberrypi connectd_start[427]: PID file specified as /var/run/Connectdrmt365535.pid
Mar 11 09:55:36 raspberrypi connectd_start[427]: setting web config port to dest_server_port 80
Mar 11 09:55:36 raspberrypi connectd_start[427]: primary local ip = 192.168.184.25
Mar 11 09:55:36 raspberrypi Connectd[923]:   Using device uid = 80:00:00:00:01:03:e4:b7
Mar 11 09:55:36 raspberrypi Connectd[923]: initialize proxy client target 127.0.0.1 port 65535
Mar 11 09:55:36 raspberrypi Connectd[923]: 35665> Remot3it Registration Code Provided (checkhash 4a:1a)#012
Mar 11 09:55:36 raspberrypi connectd_start[427]: Connectd daemon start/stop script Version: 2.4.26
Mar 11 09:55:36 raspberrypi connectd_start[427]: Starting Connectdssh54001...
Mar 11 09:55:36 raspberrypi Connectd[940]: Connectd Target built Apr 19 2019 at 16:45:30
Mar 11 09:55:36 raspberrypi Connectd[940]:    Version 4.6 - (c)2019 remot3.it, Inc. All Rights Reserved
Mar 11 09:55:36 raspberrypi Connectd[940]: Starting up as daemon
Mar 11 09:55:36 raspberrypi Connectd[940]: Parent Exited Normally.
Mar 11 09:55:36 raspberrypi Connectd[941]: Begin Startup.
Mar 11 09:55:36 raspberrypi Connectd[942]: Creating pidfile /var/run/Connectdssh54001.pid with PID 942
Mar 11 09:55:36 raspberrypi connectd_start[427]: Connectd built Apr 19 2019 at 16:45:30 Now Starting Up
Mar 11 09:55:36 raspberrypi connectd_start[427]:    Version 4.6 - (c)2019 remot3.it, Inc. All Rights Reserved
Mar 11 09:55:36 raspberrypi connectd_start[427]:    Built with ALIGN BCASTER MALLOC_POOL LINUX RESOLVE BIGBUF BACKTRACE pool=524288
Mar 11 09:55:36 raspberrypi connectd_start[427]:    Raspberry Pi Version
Mar 11 09:55:36 raspberrypi connectd_start[427]: config file //etc/connectd/services/Connectdssh54001.conf
Mar 11 09:55:36 raspberrypi connectd_start[427]: Starting up as daemon
Mar 11 09:55:36 raspberrypi connectd_start[427]: PID file specified as /var/run/Connectdssh54001.pid
Mar 11 09:55:36 raspberrypi connectd_start[427]: setting web config port to dest_server_port 80
Mar 11 09:55:36 raspberrypi connectd_start[427]: primary local ip = 192.168.184.25
Mar 11 09:55:36 raspberrypi Connectd[942]:   Using device uid = 80:00:00:00:01:03:e4:ba
Mar 11 09:55:36 raspberrypi Connectd[942]: initialize proxy client target 127.0.0.1 port 54001
Mar 11 09:55:36 raspberrypi Connectd[942]: 35665> Remot3it Registration Code Provided (checkhash b2:32)#012
Mar 11 09:55:37 raspberrypi Connectd[923]: 35677> Status redirect to  54.71.174.229:5962#012
Mar 11 09:55:37 raspberrypi Connectd[942]: 35677> Status redirect to  54.71.174.229:5964#012
Mar 11 09:55:41 raspberrypi root: [connectd_start] 
Mar 11 09:55:41 raspberrypi root: [connectd_start] Call dprovision
Mar 11 09:55:41 raspberrypi root: /usr/bin/connectd_control -v dprovision  
Mar 11 09:55:41 raspberrypi connectd_start[427]: /usr/bin/connectd_control: 790: local: bulk_identification_code.txt.: bad variable name
Mar 11 09:55:41 raspberrypi root: [connectd_start]
Mar 11 09:55:41 raspberrypi root: [connectd_start] Call bprovision
Mar 11 09:55:41 raspberrypi Connectd[923]: 35717> NAT type selected at 3 with natmap 2#012
Mar 11 09:55:41 raspberrypi Connectd[923]: Server Connection changed to state 4 
Mar 11 09:55:41 raspberrypi root: /usr/bin/connectd_control bprovision all  
Mar 11 09:55:41 raspberrypi Connectd[942]: 35717> NAT type selected at 3 with natmap 2#012
Mar 11 09:55:41 raspberrypi Connectd[942]: Server Connection changed to state 4 
Mar 11 09:55:41 raspberrypi root: [connectd_start] FAIL: nothing to provision
Mar 11 09:55:41 raspberrypi root: /usr/bin/connectd_control start all  
Mar 11 09:55:41 raspberrypi root: /usr/bin/connectd_start started: FAIL: No active devices to start
Mar 11 09:55:41 raspberrypi root: [connectd_start] connectd_d2d start
Mar 11 09:55:41 raspberrypi root: [connectd_start] exit
Mar 11 09:55:41 raspberrypi Connectd[923]: Server Connection changed to state 5 
Mar 11 09:55:41 raspberrypi Connectd[923]: Connected to server is 54.71.174.229:5962 
Mar 11 09:55:41 raspberrypi Connectd[942]: Server Connection changed to state 5 
Mar 11 09:55:41 raspberrypi Connectd[942]: Connected to server is 54.71.174.229:5964 
Mar 11 09:55:43 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Mar 11 09:57:05 raspberrypi systemd-timesyncd[275]: Synchronized to time server for the first time 217.147.208.1:123 (2.debian.pool.ntp.org).
Mar 11 09:57:05 raspberrypi systemd[1]: Starting Daily apt download activities...
Mar 11 09:57:08 raspberrypi systemd[1]: apt-daily.service: Succeeded.
Mar 11 09:57:08 raspberrypi systemd[1]: Started Daily apt download activities.
Mar 11 09:57:13 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Mar 11 09:58:01 raspberrypi systemd[1]: Started Session c3 of user pi.
Mar 11 09:59:43 raspberrypi dhcpcd[390]: wwan0: carrier lost
Mar 11 09:59:43 raspberrypi avahi-daemon[330]: Interface wwan0.IPv6 no longer relevant for mDNS.
Mar 11 09:59:43 raspberrypi avahi-daemon[330]: Leaving mDNS multicast group on interface wwan0.IPv6 with address fe80::3259:585c:8645:cb10.
Mar 11 09:59:43 raspberrypi avahi-daemon[330]: Interface wwan0.IPv4 no longer relevant for mDNS.
Mar 11 09:59:43 raspberrypi avahi-daemon[330]: Leaving mDNS multicast group on interface wwan0.IPv4 with address 169.254.23.65.
Mar 11 09:59:43 raspberrypi avahi-daemon[330]: Withdrawing address record for fe80::3259:585c:8645:cb10 on wwan0.
Mar 11 09:59:43 raspberrypi avahi-daemon[330]: Withdrawing address record for 169.254.23.65 on wwan0.
Mar 11 09:59:44 raspberrypi dhcpcd[390]: wwan0: deleting address fe80::3259:585c:8645:cb10
Mar 11 09:59:44 raspberrypi dhcpcd[390]: wwan0: deleting route to 169.254.0.0/16
Mar 11 09:59:44 raspberrypi dhcpcd[390]: wwan0: carrier acquired
Mar 11 09:59:44 raspberrypi dhcpcd[390]: wwan0: IAID 73:08:cf:45
Mar 11 09:59:44 raspberrypi dhcpcd[390]: wwan0: waiting for 3rd party to configure IP address
Mar 11 09:59:44 raspberrypi udhcpc[1209]: wwan0: deconfigured
Mar 11 09:59:44 raspberrypi dhcpcd[390]: wwan0: soliciting an IPv6 router
Mar 11 09:59:53 raspberrypi udhcpc[1209]: wwan0: configuration failed: leasefail: 
Mar 11 10:00:23 raspberrypi udhcpc[1209]: wwan0: configuration failed: leasefail: 
Mar 11 10:00:52 raspberrypi udhcpc[1209]: wwan0: configuration failed: leasefail: 
Mar 11 10:01:21 raspberrypi udhcpc[1209]: wwan0: configuration failed: leasefail: 
Mar 11 10:01:49 raspberrypi systemd[1]: Started Session c4 of user pi.
Mar 11 10:01:50 raspberrypi udhcpc[1209]: wwan0: configuration failed: leasefail: 
Mar 11 10:02:06 raspberrypi systemd[1]: Started Session c5 of user pi.
So i focused to the error message:
wwan0: configuration failed: leasefail:
I have no idea what the problem is. I tried for 7 hours last night to find the error, unfortunately without success.
Could the issue be in my service file?

Every time i reboot the Pi, everything works fine. But this is not a solution, as the raspberry must operate autonomously in a remote location using solar power.

Thank you and best regards
Maisen

shikmywaifu
Posts: 2
Joined: Mon Aug 17, 2020 7:50 am

Re: Wondershare SIM7600E 4G HAT internet connection only after reboot or restart service

Mon Aug 17, 2020 8:06 am

Hi, Do you have any updates regarding to your problem ?

Return to “Networking and servers”