Raspberry Pi Zero再起動時にCANDY Pi Liteサービスの起動に失敗する

こんにちは。
CANDY Pi Lite LTE M を購入してラズパイZeroに載せてセットアップを行いました。
OSはRasbian busterです。
セットアップ自体は完了して問題なく動作もしていたのですが、
1週間以上連続運用した後に再起動するとネットワークに接続できません。

その時に sudo systemctl status candy-pi-lite.service と実行した際の結果は以下です。


どのように対応すれば良いかご教授願います。

ご質問ありがとうございます。
原因を探るには、ログ(syslog)を確認する必要があります。
問題が起きた時刻およびそれ以前のsyslog(ファイルの場所は、/var/log/syslogです)の内容を投稿していただけますでしょうか。
秘匿したい情報などがある場合は加工していただいて構いません。
よろしくお願いいたします。

返信ありがとうございます。ログは以下です。
現象が起こると、OSが立ち上がらなくなる場合や、OSは起動するがCANDY Pi Liteサービスが起動しない場合があります。

Aug 10 14:39:13 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:39:13 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:39:13 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:39:13 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 3.
Aug 10 14:39:13 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:39:13 **** systemd[1]: Started Python Program mqtt_subscriber.py.
Aug 10 14:39:39 **** hostapd: wlan0: STA 80:38:96:e9:2a:07 IEEE 802.11: associated
Aug 10 14:39:40 **** hostapd: wlan0: STA 80:38:96:e9:2a:07 RADIUS: starting accounting session 0B802824EB5A0015
Aug 10 14:39:40 **** hostapd: wlan0: STA 80:38:96:e9:2a:07 WPA: pairwise key handshake completed (RSN)
Aug 10 14:39:40 **** dnsmasq-dhcp[491]: DHCPDISCOVER(wlan0) 80:38:96:e9:2a:07
Aug 10 14:39:40 **** dnsmasq-dhcp[491]: DHCPOFFER(wlan0) 192.168.22.35 80:38:96:e9:2a:07
Aug 10 14:39:40 **** dnsmasq-dhcp[491]: DHCPREQUEST(wlan0) 192.168.22.35 80:38:96:e9:2a:07
Aug 10 14:39:40 **** dnsmasq-dhcp[491]: DHCPACK(wlan0) 192.168.22.35 80:38:96:e9:2a:07
Aug 10 14:40:01 **** CRON[877]: (root) CMD ([881] python3 /home/nextpi/Public/Development/python/mqtt_publisher.py 2> /home/nextpi/Public/Development/python/log/puberr.log)
Aug 10 14:40:15 **** CRON[877]: (CRON) info (No MTA installed, discarding output)
Aug 10 14:40:15 **** CRON[877]: (root) END ([881] python3 /home/nextpi/Public/Development/python/mqtt_publisher.py 2> /home/nextpi/Public/Development/python/log/puberr.log)
(省略)
Aug 10 14:40:17 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:40:17 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:40:17 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:40:17 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 4.
Aug 10 14:40:17 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:40:17 **** systemd[1]: Started Python Program mqtt_subscriber.py.
(省略)
Aug 10 14:41:20 **** mqtt_subscriber.sh[907]: socket.gaierror: [Errno -3] Temporary failure in name resolution
Aug 10 14:41:20 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:41:20 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:41:21 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:41:21 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 5.
Aug 10 14:41:21 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:41:21 **** systemd[1]: Started Python Program mqtt_subscriber.py.
(省略)
Aug 10 14:42:23 **** mqtt_subscriber.sh[987]: socket.gaierror: [Errno -3] Temporary failure in name resolution
Aug 10 14:42:24 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:42:24 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:42:24 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:42:24 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 6.
Aug 10 14:42:24 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:42:24 **** systemd[1]: Started Python Program mqtt_subscriber.py.
Aug 10 14:42:35 **** systemd[1]: Stopping Python Program mqtt_subscriber.py…
Aug 10 14:42:35 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=killed, status=15/TERM
Aug 10 14:42:35 **** systemd[1]: mqtt_subscriber.service: Succeeded.
Aug 10 14:42:35 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:44:19 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:19 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:44:19 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:44:19 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:44:19 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:44:19 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 1.
Aug 10 14:44:19 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:19 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:19 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:44:19 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:44:19 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 2.
Aug 10 14:44:20 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:20 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:20 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 3.
Aug 10 14:44:20 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:20 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:20 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:44:20 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 4.
Aug 10 14:44:21 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:21 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:21 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 5.
Aug 10 14:44:21 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Start request repeated too quickly.
Aug 10 14:44:21 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:44:21 **** systemd[1]: Failed to start CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:50:01 **** CRON[1644]: (root) CMD ([1648] python3 /home/nextpi/Public/Development/python/mqtt_publisher.py 2> /home/nextpi/Public/Development/python/log/puberr.log)
Aug 10 14:50:15 **** CRON[1644]: (CRON) info (No MTA installed, discarding output)
Aug 10 14:50:15 **** CRON[1644]: (root) END ([1648] python3 /home/nextpi/Public/Development/python/mqtt_publisher.py 2> /home/nextpi/Public/Development/python/log/puberr.log)
Aug 10 14:50:24 **** systemd[1]: Starting Cleanup of Temporary Directories…
Aug 10 14:50:24 **** systemd-tmpfiles[1678]: [/usr/lib/tmpfiles.d/vsftpd.conf:1] Line references path below legacy directory /var/run/, updating /var/run/vsftpd/empty → /run/vsftpd/empty; please update the tmpfiles.d/ drop-in file accordingly.
Aug 10 14:50:25 **** systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Aug 10 14:50:25 **** systemd[1]: Started Cleanup of Temporary Directories.
Aug 10 14:50:49 **** systemd[1]: Condition check resulted in Turns off Raspberry Pi display backlight on shutdown/reboot being skipped.
Aug 10 14:50:49 **** systemd[1]: Unmounting RPC Pipe File System…
Aug 10 14:50:49 **** systemd[1]: Removed slice system-bthelper.slice.
Aug 10 14:50:49 **** systemd[1]: Stopped target Timers.
Aug 10 14:50:49 **** systemd[1]: systemd-tmpfiles-clean.timer: Succeeded.
Aug 10 14:50:49 **** systemd[1]: Stopped Daily Cleanup of Temporary Directories.
Aug 10 14:50:49 **** systemd[1]: Stopped target Sound Card.
Aug 10 14:50:49 **** systemd[1]: Stopping Save/Restore Sound Card State…
Aug 10 14:50:49 **** systemd[1]: Stopped target Multi-User System.
Aug 10 14:50:49 **** systemd[1]: rpi-eeprom-update.service: Succeeded.
Aug 10 14:50:49 **** systemd[1]: Stopped Check for Raspberry Pi EEPROM updates.
Aug 10 14:50:49 **** systemd[1]: Stopping triggerhappy global hotkey daemon…
Aug 10 14:50:50 **** systemd[1]: Stopping vsftpd FTP server…
Aug 10 14:50:50 **** systemd[1]: Stopped target Login Prompts.
Aug 10 14:50:50 **** systemd[1]: Stopping Getty on tty1…
Aug 10 14:50:50 **** systemd[1]: Stopping rng-tools.service…
Aug 10 14:50:50 **** systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator…
Aug 10 14:50:50 **** systemd[1]: Stopping OpenBSD Secure Shell server…
Aug 10 14:50:50 **** systemd[1]: gldriver-test.service: Succeeded.
Aug 10 14:50:50 **** systemd[1]: Stopped Check for v3d driver.
Aug 10 14:50:50 **** systemd[1]: Stopping BluezALSA proxy…
Aug 10 14:50:50 **** bluetoothd[488]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/Source/1
Aug 10 14:50:50 **** bluetoothd[488]: Endpoint unregistered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/Source/2
Aug 10 14:50:50 **** rngd[296]: stats: bits received from HRNG source: 60064
Aug 10 14:50:50 **** rngd[296]: stats: bits sent to kernel pool: 11776
Aug 10 14:50:50 **** rngd[296]: stats: entropy added to kernel pool: 11776
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2 successes: 3
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2 failures: 0
Aug 10 14:50:50 **** systemd[1]: Stopping LSB: Switch to ondemand cpu governor (unless shift key is pressed)…
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 10 14:50:50 **** systemd[1]: Stopping Python Program port_surveillance.py…
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 10 14:50:50 **** systemd[1]: systemd-rfkill.socket: Succeeded.
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 10 14:50:50 **** systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 10 14:50:50 **** systemd[1]: Stopping Login Service…
Aug 10 14:50:50 **** rngd[296]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 10 14:50:50 **** systemd[1]: apt-daily-upgrade.timer: Succeeded.
Aug 10 14:50:50 **** kernel: [ 929.129290] Bluetooth: hci0: sending frame failed (-49)
Aug 10 14:50:50 **** rngd[296]: stats: HRNG source speed: (min=101.060; avg=118.002; max=129.120)Kibits/s
Aug 10 14:50:50 **** systemd[1]: Stopped Daily apt upgrade and clean activities.
Aug 10 14:50:50 **** rngd[296]: stats: FIPS tests speed: (min=404.533; avg=1029.731; max=5844.180)Kibits/s
Aug 10 14:50:50 **** systemd[1]: apt-daily.timer: Succeeded.
Aug 10 14:51:11 **** kernel: [ 0.000000] Booting Linux on physical CPU 0x0
Aug 10 14:51:11 **** systemd-modules-load[84]: Inserted module ‘i2c_dev’
Aug 10 14:51:11 **** fake-hwclock[82]: 2020年 8月 10日 月曜日 05:50:54 UTC
Aug 10 14:51:11 **** systemd-fsck[94]: e2fsck 1.44.5 (15-Dec-2018)
Aug 10 14:51:11 **** systemd-fsck[94]: root: clean, 188977/1767248 files, 1764053/7090304 blocks
Aug 10 14:51:11 **** systemd[1]: Started File System Check on Root Device.
Aug 10 14:51:11 **** systemd[1]: Starting Remount Root and Kernel File Systems…
Aug 10 14:51:11 **** systemd[1]: Started udev Coldplug all Devices.
Aug 10 14:51:11 **** systemd[1]: Starting Helper to synchronize boot up for ifupdown…
Aug 10 14:51:11 **** systemd[1]: Started Set the console keyboard layout.
Aug 10 14:51:11 **** systemd[1]: Started Remount Root and Kernel File Systems.
Aug 10 14:51:11 **** systemd[1]: Started Helper to synchronize boot up for ifupdown.
Aug 10 14:51:11 **** kernel: [ 0.000000] Linux version 5.4.51+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1327 Thu Jul 23 10:53:06 BST 2020
Aug 10 14:51:11 **** kernel: [ 0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
Aug 10 14:51:11 **** kernel: [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
Aug 10 14:51:11 **** kernel: [ 0.000000] OF: fdt: Machine model: Raspberry Pi Zero W Rev 1.1
Aug 10 14:51:11 **** kernel: [ 0.000000] Memory policy: Data cache writeback
Aug 10 14:51:11 **** kernel: [ 0.000000] Reserved memory: created CMA memory pool at 0x17c00000, size 64 MiB
Aug 10 14:51:11 **** kernel: [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
Aug 10 14:51:11 **** kernel: [ 0.000000] On node 0 totalpages: 114688
Aug 10 14:51:11 **** kernel: [ 0.000000] Normal zone: 896 pages used for memmap
Aug 10 14:51:11 **** kernel: [ 0.000000] Normal zone: 0 pages reserved
Aug 10 14:51:11 **** kernel: [ 0.000000] Normal zone: 114688 pages, LIFO batch:31
Aug 10 14:51:11 **** kernel: [ 0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Aug 10 14:51:11 **** kernel: [ 0.000000] pcpu-alloc: [0] 0
Aug 10 14:51:11 **** systemd[1]: Starting Flush Journal to Persistent Storage…
Aug 10 14:51:11 **** systemd[1]: Starting Load/Save Random Seed…
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Aug 10 14:51:11 **** systemd[1]: Starting Create System Users…
Aug 10 14:51:11 **** systemd[1]: Started Load/Save Random Seed.
Aug 10 14:51:11 **** systemd[1]: Started Flush Journal to Persistent Storage.
Aug 10 14:51:11 **** systemd[1]: Started Create System Users.
Aug 10 14:51:11 **** systemd[1]: Starting Create Static Device Nodes in /dev…
Aug 10 14:51:11 **** systemd-tmpfiles[107]: [/usr/lib/tmpfiles.d/vsftpd.conf:1] Line references path below legacy directory /var/run/, updating /var/run/vsftpd/empty → /run/vsftpd/empty; please update the tmpfiles.d/ drop-in file accordingly.
Aug 10 14:51:11 **** systemd[1]: Started Create Static Device Nodes in /dev.
Aug 10 14:51:11 **** systemd[1]: Starting udev Kernel Device Manager…
Aug 10 14:51:11 **** systemd[1]: Reached target Local File Systems (Pre).
Aug 10 14:51:11 **** systemd[1]: Started udev Kernel Device Manager.
Aug 10 14:51:11 **** systemd[1]: Starting Show Plymouth Boot Screen…
Aug 10 14:51:11 **** systemd[1]: Received SIGRTMIN+20 from PID 113 (plymouthd).
Aug 10 14:51:11 **** systemd[1]: Started Show Plymouth Boot Screen.
Aug 10 14:51:11 **** systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
Aug 10 14:51:11 **** systemd[1]: Reached target Paths.
Aug 10 14:51:11 **** kernel: [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 113792
Aug 10 14:51:11 **** kernel: [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 smsc95xx.macaddr=B8:27:EB:75:70:3A vc_mem.mem_base=0x1ec00000 vc_mem.mem_size=0x20000000 console=tty1 root=/dev/mmcblk0p7 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
Aug 10 14:51:11 **** kernel: [ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Aug 10 14:51:11 **** kernel: [ 0.000000] Memory: 377108K/458752K available (7474K kernel code, 694K rwdata, 2384K rodata, 480K init, 799K bss, 16108K reserved, 65536K cma-reserved)
Aug 10 14:51:11 **** kernel: [ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Aug 10 14:51:11 **** kernel: [ 0.000000] ftrace: allocating 26388 entries in 52 pages
Aug 10 14:51:11 **** kernel: [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
Aug 10 14:51:11 **** kernel: [ 0.000000] random: get_random_bytes called from start_kernel+0x2a8/0x4c4 with crng_init=0
Aug 10 14:51:11 **** kernel: [ 0.000019] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
Aug 10 14:51:11 **** kernel: [ 0.000076] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
Aug 10 14:51:11 **** kernel: [ 0.000177] bcm2835: system timer (irq = 27)
Aug 10 14:51:11 **** kernel: [ 0.000760] Console: colour dummy device 80x30
Aug 10 14:51:11 **** kernel: [ 0.001325] printk: console [tty1] enabled
Aug 10 14:51:11 **** kernel: [ 0.001413] Calibrating delay loop… 697.95 BogoMIPS (lpj=3489792)
Aug 10 14:51:11 **** kernel: [ 0.050350] pid_max: default: 32768 minimum: 301
Aug 10 14:51:11 **** kernel: [ 0.050821] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 0.050886] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 0.052336] CPU: Testing write buffer coherency: ok
Aug 10 14:51:11 **** kernel: [ 0.053825] Setting up static identity map for 0x8200 - 0x8238
Aug 10 14:51:11 **** kernel: [ 0.054808] devtmpfs: initialized
Aug 10 14:51:11 **** kernel: [ 0.067034] VFP support v0.3: implementor 41 architecture 1 part 20 variant b rev 5
Aug 10 14:51:11 **** kernel: [ 0.067512] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Aug 10 14:51:11 **** kernel: [ 0.067593] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 0.075330] pinctrl core: initialized pinctrl subsystem
Aug 10 14:51:11 **** kernel: [ 0.077095] NET: Registered protocol family 16
Aug 10 14:51:11 **** kernel: [ 0.081698] DMA: preallocated 1024 KiB pool for atomic coherent allocations
Aug 10 14:51:11 **** kernel: [ 0.089203] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
Aug 10 14:51:11 **** kernel: [ 0.089275] hw-breakpoint: maximum watchpoint size is 4 bytes.
Aug 10 14:51:11 **** kernel: [ 0.089459] Serial: AMBA PL011 UART driver
Aug 10 14:51:11 **** kernel: [ 0.093123] bcm2835-mbox 2000b880.mailbox: mailbox enabled
Aug 10 14:51:11 **** kernel: [ 0.120715] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-07-17 11:04, variant start
Aug 10 14:51:11 **** kernel: [ 0.130735] raspberrypi-firmware soc:firmware: Firmware hash is 21a15cb094f41c7506ad65d2cb9b29c550693057
Aug 10 14:51:11 **** kernel: [ 0.189441] bcm2835-dma 20007000.dma: DMA legacy API manager, dmachans=0x1
Aug 10 14:51:11 **** kernel: [ 0.192531] SCSI subsystem initialized
Aug 10 14:51:11 **** kernel: [ 0.192830] usbcore: registered new interface driver usbfs
Aug 10 14:51:11 **** kernel: [ 0.192966] usbcore: registered new interface driver hub
Aug 10 14:51:11 **** kernel: [ 0.193215] usbcore: registered new device driver usb
Aug 10 14:51:11 **** kernel: [ 0.195778] clocksource: Switched to clocksource timer
Aug 10 14:51:11 **** kernel: [ 1.443593] VFS: Disk quotas dquot_6.6.0
Aug 10 14:51:11 **** kernel: [ 1.443759] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Aug 10 14:51:11 **** kernel: [ 1.444099] FS-Cache: Loaded
Aug 10 14:51:11 **** kernel: [ 1.444482] CacheFiles: Loaded
Aug 10 14:51:11 **** kernel: [ 1.461707] thermal_sys: Registered thermal governor ‘step_wise’
Aug 10 14:51:11 **** kernel: [ 1.462332] NET: Registered protocol family 2
Aug 10 14:51:11 **** kernel: [ 1.463720] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 1.463823] TCP established hash table entries: 4096 (order: 2, 16384 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 1.463946] TCP bind hash table entries: 4096 (order: 2, 16384 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 1.464070] TCP: Hash tables configured (established 4096 bind 4096)
Aug 10 14:51:11 **** kernel: [ 1.464257] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 1.464327] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
Aug 10 14:51:11 **** kernel: [ 1.464743] NET: Registered protocol family 1
Aug 10 14:51:11 **** kernel: [ 1.466049] RPC: Registered named UNIX socket transport module.
Aug 10 14:51:11 **** kernel: [ 1.466110] RPC: Registered udp transport module.
Aug 10 14:51:11 **** kernel: [ 1.466144] RPC: Registered tcp transport module.
Aug 10 14:51:11 **** kernel: [ 1.466174] RPC: Registered tcp NFSv4.1 backchannel transport module.
Aug 10 14:51:11 **** kernel: [ 1.467637] hw perfevents: no irqs for PMU, sampling events not supported
Aug 10 14:51:11 **** kernel: [ 1.467749] hw perfevents: enabled with armv6_1176 PMU driver, 3 counters available
Aug 10 14:51:11 **** kernel: [ 1.471899] Initialise system trusted keyrings
Aug 10 14:51:11 **** kernel: [ 1.472562] workingset: timestamp_bits=30 max_order=17 bucket_order=0
Aug 10 14:51:11 **** kernel: [ 1.486799] FS-Cache: Netfs ‘nfs’ registered for caching
Aug 10 14:51:11 **** kernel: [ 1.488245] NFS: Registering the id_resolver key type
Aug 10 14:51:11 **** kernel: [ 1.488341] Key type id_resolver registered
Aug 10 14:51:11 **** kernel: [ 1.488379] Key type id_legacy registered
Aug 10 14:51:11 **** kernel: [ 1.488430] nfs4filelayout_init: NFSv4 File Layout Driver Registering…
Aug 10 14:51:11 **** kernel: [ 1.490385] Key type asymmetric registered
Aug 10 14:51:11 **** kernel: [ 1.490450] Asymmetric key parser ‘x509’ registered
Aug 10 14:51:11 **** kernel: [ 1.490560] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
Aug 10 14:51:11 **** kernel: [ 1.490611] io scheduler mq-deadline registered
Aug 10 14:51:11 **** kernel: [ 1.490646] io scheduler kyber registered
Aug 10 14:51:11 **** kernel: [ 1.493887] bcm2708_fb soc:fb: FB found 1 display(s)
Aug 10 14:51:11 **** kernel: [ 1.505553] Console: switching to colour frame buffer device 82x26
Aug 10 14:51:11 **** kernel: [ 1.512922] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 656x416
Aug 10 14:51:11 **** kernel: [ 1.523507] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
Aug 10 14:51:11 **** kernel: [ 1.530478] bcm2835-rng 20104000.rng: hwrng registered
Aug 10 14:51:11 **** kernel: [ 1.534150] vc-mem: phys_addr:0x00000000 mem_base=0x1ec00000 mem_size:0x20000000(512 MiB)
Aug 10 14:51:11 **** kernel: [ 1.541186] vc-sm: Videocore shared memory driver
Aug 10 14:51:11 **** kernel: [ 1.545008] gpiomem-bcm2835 20200000.gpiomem: Initialised: Registers at 0x20200000
Aug 10 14:51:11 **** kernel: [ 1.570507] brd: module loaded
Aug 10 14:51:11 **** kernel: [ 1.587910] loop: module loaded
Aug 10 14:51:11 **** kernel: [ 1.592990] Loading iSCSI transport class v2.0-870.
Aug 10 14:51:11 **** kernel: [ 1.597146] usbcore: registered new interface driver smsc95xx
Aug 10 14:51:11 **** kernel: [ 1.600201] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
Aug 10 14:51:11 **** kernel: [ 2.331484] Core Release: 2.80a
Aug 10 14:51:11 **** kernel: [ 2.334463] Setting default values for core params
Aug 10 14:51:11 **** kernel: [ 2.337419] Finished setting default values for core params
Aug 10 14:51:11 **** kernel: [ 2.505778] random: fast init done
Aug 10 14:51:11 **** kernel: [ 2.543682] Using Buffer DMA mode
Aug 10 14:51:11 **** kernel: [ 2.546624] Periodic Transfer Interrupt Enhancement - disabled
Aug 10 14:51:11 **** kernel: [ 2.549527] Multiprocessor Interrupt Enhancement - disabled
Aug 10 14:51:11 **** kernel: [ 2.552373] OTG VER PARAM: 0, OTG VER FLAG: 0
Aug 10 14:51:11 **** kernel: [ 2.555155] Dedicated Tx FIFOs mode
Aug 10 14:51:11 **** kernel: [ 2.558814] WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = d7d14000 dma = 0x57d14000 len=9024
Aug 10 14:51:11 **** kernel: [ 2.564369] FIQ FSM acceleration enabled for :
Aug 10 14:51:11 **** kernel: [ 2.564369] Non-periodic Split Transactions
Aug 10 14:51:11 **** kernel: [ 2.564369] Periodic Split Transactions
Aug 10 14:51:11 **** kernel: [ 2.564369] High-Speed Isochronous Endpoints
Aug 10 14:51:11 **** kernel: [ 2.564369] Interrupt/Control Split Transaction hack enabled
Aug 10 14:51:11 **** kernel: [ 2.577023] dwc_otg: Microframe scheduler enabled
Aug 10 14:51:11 **** kernel: [ 2.577227] WARN::hcd_init_fiq:457: FIQ on core 0
Aug 10 14:51:11 **** kernel: [ 2.579833] WARN::hcd_init_fiq:458: FIQ ASM at c05500d4 length 36
Aug 10 14:51:11 **** kernel: [ 2.582404] WARN::hcd_init_fiq:497: MPHI regs_base at dc810000
Aug 10 14:51:11 **** kernel: [ 2.584944] dwc_otg 20980000.usb: DWC OTG Controller
Aug 10 14:51:11 **** kernel: [ 2.587555] dwc_otg 20980000.usb: new USB bus registered, assigned bus number 1
Aug 10 14:51:11 **** kernel: [ 2.590173] dwc_otg 20980000.usb: irq 56, io mem 0x00000000
Aug 10 14:51:11 **** kernel: [ 2.592744] Init: Port Power? op_state=1
Aug 10 14:51:11 **** kernel: [ 2.595217] Init: Power Port (0)
Aug 10 14:51:11 **** kernel: [ 2.598193] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
Aug 10 14:51:11 **** kernel: [ 2.603268] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Aug 10 14:51:11 **** kernel: [ 2.605988] usb usb1: Product: DWC OTG Controller
Aug 10 14:51:11 **** kernel: [ 2.608640] usb usb1: Manufacturer: Linux 5.4.51+ dwc_otg_hcd
Aug 10 14:51:11 **** kernel: [ 2.611336] usb usb1: SerialNumber: 20980000.usb
Aug 10 14:51:11 **** kernel: [ 2.615075] hub 1-0:1.0: USB hub found
Aug 10 14:51:11 **** kernel: [ 2.617847] hub 1-0:1.0: 1 port detected
Aug 10 14:51:11 **** kernel: [ 2.621545] dwc_otg: FIQ enabled
Aug 10 14:51:11 **** kernel: [ 2.621562] dwc_otg: NAK holdoff enabled
Aug 10 14:51:11 **** kernel: [ 2.621574] dwc_otg: FIQ split-transaction FSM enabled
Aug 10 14:51:11 **** kernel: [ 2.621595] Module dwc_common_port init
Aug 10 14:51:11 **** kernel: [ 2.622126] usbcore: registered new interface driver usb-storage
Aug 10 14:51:11 **** kernel: [ 2.625193] mousedev: PS/2 mouse device common for all mice
Aug 10 14:51:11 **** kernel: [ 2.629846] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
Aug 10 14:51:11 **** kernel: [ 2.633033] bcm2835-cpufreq: min=700000 max=1000000
Aug 10 14:51:11 **** kernel: [ 2.637188] sdhci: Secure Digital Host Controller Interface driver

※ログ続き
Aug 10 14:51:11 **** kernel: [ 2.639908] sdhci: Copyright© Pierre Ossman
Aug 10 14:51:11 **** kernel: [ 2.643404] mmc-bcm2835 20300000.mmcnr: could not get clk, deferring probe
Aug 10 14:51:11 **** kernel: [ 2.647453] sdhost-bcm2835 20202000.mmc: could not get clk, deferring probe
Aug 10 14:51:11 **** kernel: [ 2.650724] sdhci-pltfm: SDHCI platform and OF driver helper
Aug 10 14:51:11 **** kernel: [ 2.654403] ledtrig-cpu: registered to indicate activity on CPUs
Aug 10 14:51:11 **** kernel: [ 2.657840] hidraw: raw HID events driver © Jiri Kosina
Aug 10 14:51:11 **** kernel: [ 2.660998] usbcore: registered new interface driver usbhid
Aug 10 14:51:11 **** kernel: [ 2.663938] usbhid: USB HID core driver
Aug 10 14:51:11 **** kernel: [ 2.668144] vchiq: vchiq_init_state: slot_zero = (ptrval)
Aug 10 14:51:11 **** kernel: [ 2.672914] [vc_sm_connected_init]: start
Aug 10 14:51:11 **** kernel: [ 2.682192] [vc_sm_connected_init]: end - returning 0
Aug 10 14:51:11 **** kernel: [ 2.687732] Initializing XFRM netlink socket
Aug 10 14:51:11 **** kernel: [ 2.690448] NET: Registered protocol family 17
Aug 10 14:51:11 **** kernel: [ 2.693265] Key type dns_resolver registered
Aug 10 14:51:11 **** kernel: [ 2.697206] registered taskstats version 1
Aug 10 14:51:11 **** kernel: [ 2.699984] Loading compiled-in X.509 certificates
Aug 10 14:51:11 **** kernel: [ 2.717768] uart-pl011 20201000.serial: cts_event_workaround enabled
Aug 10 14:51:11 **** kernel: [ 2.720677] 20201000.serial: ttyAMA0 at MMIO 0x20201000 (irq = 81, base_baud = 0) is a PL011 rev2
Aug 10 14:51:11 **** kernel: [ 2.729614] 20215040.serial: ttyS0 at MMIO 0x0 (irq = 53, base_baud = 50000000) is a 16550
Aug 10 14:51:11 **** kernel: [ 2.736599] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
Aug 10 14:51:11 **** kernel: [ 2.741699] mmc-bcm2835 20300000.mmcnr: mmc_debug:0 mmc_debug2:0
Aug 10 14:51:11 **** kernel: [ 2.744702] mmc-bcm2835 20300000.mmcnr: DMA channel allocated
Aug 10 14:51:11 **** kernel: [ 2.777246] sdhost: log_buf @ (ptrval) (57d13000)
Aug 10 14:51:11 **** kernel: [ 2.817336] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
Aug 10 14:51:11 **** kernel: [ 2.821982] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Aug 10 14:51:11 **** kernel: [ 2.826422] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Aug 10 14:51:11 **** kernel: [ 2.829149] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Aug 10 14:51:11 **** kernel: [ 2.835112] of_cfs_init
Aug 10 14:51:11 **** kernel: [ 2.858545] Indeed it is in host mode hprt0 = 00021501
Aug 10 14:51:11 **** kernel: [ 2.921698] of_cfs_init: OK
Aug 10 14:51:11 **** kernel: [ 2.926762] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
Aug 10 14:51:11 **** kernel: [ 2.929669] Waiting for root device /dev/mmcblk0p7…
Aug 10 14:51:11 **** kernel: [ 2.997257] mmc0: host does not support reading read-only switch, assuming write-enable
Aug 10 14:51:11 **** kernel: [ 3.007676] mmc0: new high speed SDHC card at address aaaa
Aug 10 14:51:11 **** kernel: [ 3.012307] mmcblk0: mmc0:aaaa SL32G 29.7 GiB
Aug 10 14:51:11 **** kernel: [ 3.024530] mmcblk0: p1 p2 < p5 p6 p7 >
Aug 10 14:51:11 **** kernel: [ 3.058812] mmc1: new high speed SDIO card at address 0001
Aug 10 14:51:11 **** kernel: [ 3.072134] EXT4-fs (mmcblk0p7): mounted filesystem with ordered data mode. Opts: (null)
Aug 10 14:51:11 **** kernel: [ 3.077576] usb 1-1: new full-speed USB device number 2 using dwc_otg
Aug 10 14:51:11 **** kernel: [ 3.080627] Indeed it is in host mode hprt0 = 00021501
Aug 10 14:51:11 **** kernel: [ 3.143655] VFS: Mounted root (ext4 filesystem) readonly on device 179:7.
Aug 10 14:51:11 **** kernel: [ 3.157456] devtmpfs: mounted
Aug 10 14:51:11 **** kernel: [ 3.166765] Freeing unused kernel memory: 480K
Aug 10 14:51:11 **** kernel: [ 3.169686] This architecture does not have kernel memory protection.
Aug 10 14:51:11 **** kernel: [ 3.172672] Run /sbin/init as init process
Aug 10 14:51:11 **** kernel: [ 3.332582] usb 1-1: New USB device found, idVendor=0403, idProduct=6001, bcdDevice= 6.00
Aug 10 14:51:11 **** kernel: [ 3.338965] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 10 14:51:11 **** kernel: [ 3.342233] usb 1-1: Product: USB-RS485 Cable
Aug 10 14:51:11 **** kernel: [ 3.345451] usb 1-1: Manufacturer: FTDI
Aug 10 14:51:11 **** kernel: [ 3.348676] usb 1-1: SerialNumber: FT42I08Y
Aug 10 14:51:11 **** kernel: [ 4.161034] NET: Registered protocol family 10
Aug 10 14:51:11 **** kernel: [ 4.166373] Segment Routing with IPv6
Aug 10 14:51:11 **** kernel: [ 7.083796] random: systemd: uninitialized urandom read (16 bytes read)
Aug 10 14:51:11 **** kernel: [ 7.125359] random: systemd: uninitialized urandom read (16 bytes read)
Aug 10 14:51:11 **** kernel: [ 7.139317] random: systemd: uninitialized urandom read (16 bytes read)
Aug 10 14:51:11 **** kernel: [ 8.362213] i2c /dev entries driver
Aug 10 14:51:11 **** kernel: [ 10.743714] EXT4-fs (mmcblk0p7): re-mounted. Opts: (null)
Aug 10 14:51:11 **** kernel: [ 13.733528] mc: Linux media interface: v0.10
Aug 10 14:51:11 **** kernel: [ 13.804333] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 13.808632] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
Aug 10 14:51:11 **** kernel: [ 13.808679] [vc_sm_connected_init]: start
Aug 10 14:51:11 **** kernel: [ 13.819092] [vc_sm_connected_init]: installed successfully
Aug 10 14:51:11 **** kernel: [ 13.996599] videodev: Linux video capture interface: v2.00
Aug 10 14:51:11 **** kernel: [ 14.046684] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.079886] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.087226] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.088819] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.106960] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.123804] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.136205] bcm2835_audio bcm2835_audio: card created with 8 channels
Aug 10 14:51:11 **** kernel: [ 14.181850] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
Aug 10 14:51:11 **** kernel: [ 14.187179] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
Aug 10 14:51:11 **** kernel: [ 14.189183] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
Aug 10 14:51:11 **** kernel: [ 14.197948] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
Aug 10 14:51:11 **** systemd[1]: Reached target Local Encrypted Volumes.
Aug 10 14:51:11 **** systemd[1]: Found device /dev/serial1.
Aug 10 14:51:11 **** mtp-probe: checking bus 1, device 2: “/sys/devices/platform/soc/20980000.usb/usb1/1-1”
Aug 10 14:51:11 **** mtp-probe: bus: 1, device: 2 was not an MTP device
Aug 10 14:51:11 **** systemd[1]: Found device /dev/mmcblk0p6.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Huge Pages File System being skipped.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Aug 10 14:51:11 **** systemd[1]: Starting File System Check on /dev/mmcblk0p6…
Aug 10 14:51:11 **** systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
Aug 10 14:51:11 **** systemd[1]: Starting Load/Save RF Kill Switch Status…
Aug 10 14:51:11 **** systemd-fsck[172]: fsck.fat 4.1 (2017-01-24)
Aug 10 14:51:11 **** systemd-fsck[172]: /dev/mmcblk0p6: 246 files, 108926/516188 clusters
Aug 10 14:51:11 **** systemd[1]: Started File System Check on /dev/mmcblk0p6.
Aug 10 14:51:11 **** systemd[1]: Mounting /boot…
Aug 10 14:51:11 **** systemd[1]: Mounted /boot.
Aug 10 14:51:11 **** systemd[1]: Reached target Local File Systems.
Aug 10 14:51:11 **** systemd[1]: Starting Preprocess NFS configuration…
Aug 10 14:51:11 **** systemd[1]: Starting Create Volatile Files and Directories…
Aug 10 14:51:11 **** systemd[1]: Starting Set console font and keymap…
Aug 10 14:51:11 **** systemd[1]: Starting netfilter persistent configuration…
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Load AppArmor profiles being skipped.
Aug 10 14:51:11 **** systemd[1]: Starting Tell Plymouth To Write Out Runtime Data…
Aug 10 14:51:11 **** systemd[1]: nfs-config.service: Succeeded.
Aug 10 14:51:11 **** systemd[1]: Started Preprocess NFS configuration.
Aug 10 14:51:11 **** systemd[1]: Started Set console font and keymap.
Aug 10 14:51:11 **** systemd[1]: plymouth-read-write.service: Succeeded.
Aug 10 14:51:11 **** netfilter-persistent[200]: run-parts: executing /usr/share/netfilter-persistent/plugins.d/15-ip4tables start
Aug 10 14:51:11 **** systemd[1]: Started Tell Plymouth To Write Out Runtime Data.
Aug 10 14:51:11 **** systemd[1]: Received SIGRTMIN+20 from PID 113 (plymouthd).
Aug 10 14:51:11 **** netfilter-persistent[200]: Warning: skipping IPv4 (no rules to load)
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
Aug 10 14:51:11 **** netfilter-persistent[200]: run-parts: executing /usr/share/netfilter-persistent/plugins.d/25-ip6tables start
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
Aug 10 14:51:11 **** systemd[1]: Reached target NFS client services.
Aug 10 14:51:11 **** systemd-udevd[110]: Using default interface naming scheme ‘v240’.
Aug 10 14:51:11 **** systemd[1]: Reached target Remote File Systems (Pre).
Aug 10 14:51:11 **** netfilter-persistent[200]: Warning: skipping IPv6 (no rules to load)
Aug 10 14:51:11 **** systemd[1]: Reached target Remote File Systems.
Aug 10 14:51:11 **** systemd[1]: Started netfilter persistent configuration.
Aug 10 14:51:11 **** systemd[1]: Reached target Network (Pre).
Aug 10 14:51:11 **** systemd[1]: Starting Raise network interfaces…
Aug 10 14:51:11 **** systemd-tmpfiles[195]: [/usr/lib/tmpfiles.d/vsftpd.conf:1] Line references path below legacy directory /var/run/, updating /var/run/vsftpd/empty → /run/vsftpd/empty; please update the tmpfiles.d/ drop-in file accordingly.
Aug 10 14:51:11 **** systemd[1]: Started Create Volatile Files and Directories.
Aug 10 14:51:11 **** systemd[1]: Starting Update UTMP about System Boot/Shutdown…
Aug 10 14:51:11 **** systemd[1]: Started Load/Save RF Kill Switch Status.
Aug 10 14:51:11 **** systemd[1]: Started Update UTMP about System Boot/Shutdown.
Aug 10 14:51:11 **** systemd[1]: Reached target System Initialization.
Aug 10 14:51:11 **** systemd[1]: Started Daily rotation of log files.
Aug 10 14:51:11 **** systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Aug 10 14:51:11 **** systemd[1]: Listening on triggerhappy.socket.
Aug 10 14:51:11 **** systemd[1]: Started Daily apt download activities.
Aug 10 14:51:11 **** systemd[1]: Started Daily man-db regeneration.
Aug 10 14:51:11 **** systemd[1]: Started Daily Cleanup of Temporary Directories.
Aug 10 14:51:11 **** systemd[1]: Started Daily apt upgrade and clean activities.
Aug 10 14:51:11 **** systemd[1]: Reached target Timers.
Aug 10 14:51:11 **** systemd[1]: Listening on D-Bus System Message Bus Socket.
Aug 10 14:51:11 **** systemd[1]: Reached target Sockets.
Aug 10 14:51:11 **** systemd[1]: Reached target Basic System.
Aug 10 14:51:11 **** systemd[1]: Starting System Logging Service…
Aug 10 14:51:11 **** systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file…
Aug 10 14:51:11 **** systemd[1]: Started Regular background program processing daemon.
Aug 10 14:51:11 **** systemd[1]: Starting rng-tools.service…
Aug 10 14:51:11 **** cron[280]: (CRON) INFO (pidfile fd = 3)
Aug 10 14:51:11 **** cron[280]: (CRON) INFO (Running @reboot jobs)
Aug 10 14:51:11 **** systemd[1]: Starting Check for Raspberry Pi EEPROM updates…
Aug 10 14:51:11 **** rsyslogd: imuxsock: Acquired UNIX socket ‘/run/systemd/journal/syslog’ (fd 3) from systemd. [v8.1901.0]
Aug 10 14:51:11 **** rsyslogd: [origin software=“rsyslogd” swVersion=“8.1901.0” x-pid=“276” x-info=“https://www.rsyslog.com”] start
Aug 10 14:51:11 **** systemd[1]: Starting triggerhappy global hotkey daemon…
Aug 10 14:51:11 **** systemd[1]: Starting Restore /etc/resolv.conf if the system crashed before the ppp link was shut down…
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Aug 10 14:51:11 **** kernel: [ 14.210325] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
Aug 10 14:51:11 **** kernel: [ 14.210377] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
Aug 10 14:51:11 **** kernel: [ 14.210408] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
Aug 10 14:51:11 **** kernel: [ 14.210433] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
Aug 10 14:51:11 **** kernel: [ 14.210457] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
Aug 10 14:51:11 **** kernel: [ 14.210902] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
Aug 10 14:51:11 **** kernel: [ 14.248032] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
Aug 10 14:51:11 **** kernel: [ 14.248105] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
Aug 10 14:51:11 **** kernel: [ 14.289250] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
Aug 10 14:51:11 **** kernel: [ 14.289319] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
Aug 10 14:51:11 **** kernel: [ 14.316005] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
Aug 10 14:51:11 **** kernel: [ 14.316074] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
Aug 10 14:51:11 **** kernel: [ 16.393313] cfg80211: Loading compiled-in X.509 certificates for regulatory database
Aug 10 14:51:11 **** kernel: [ 16.470809] usbcore: registered new interface driver usbserial_generic
Aug 10 14:51:11 **** kernel: [ 16.470954] usbserial: USB Serial support registered for generic
Aug 10 14:51:11 **** kernel: [ 16.663429] usbcore: registered new interface driver ftdi_sio
Aug 10 14:51:11 **** kernel: [ 16.663578] usbserial: USB Serial support registered for FTDI USB Serial Device
Aug 10 14:51:11 **** kernel: [ 16.663911] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
Aug 10 14:51:11 **** kernel: [ 16.664219] usb 1-1: Detected FT232RL
Aug 10 14:51:11 **** kernel: [ 16.789431] cfg80211: Loaded X.509 cert ‘sforshee: 00b28ddf47aef9cea7’
Aug 10 14:51:11 **** kernel: [ 16.882645] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB0
Aug 10 14:51:11 **** kernel: [ 17.262954] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
Aug 10 14:51:11 **** kernel: [ 17.297030] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
Aug 10 14:51:11 **** kernel: [ 17.297453] usbcore: registered new interface driver brcmfmac
Aug 10 14:51:11 **** kernel: [ 17.338606] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43430-sdio.raspberrypi,model-zero-w.txt failed with error -2
Aug 10 14:51:11 **** kernel: [ 17.548609] random: crng init done
Aug 10 14:51:11 **** kernel: [ 17.548630] random: 7 urandom warning(s) missed due to ratelimiting
Aug 10 14:51:11 **** kernel: [ 17.595579] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43430-sdio for chip BCM43430/1
Aug 10 14:51:11 **** kernel: [ 17.595884] brcmfmac: brcmf_c_process_clm_blob: no clm_blob available (err=-2), device may have limited channels available
Aug 10 14:51:11 **** kernel: [ 17.599127] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM43430/1 wl0: Oct 22 2019 01:59:28 version 7.45.98.94 (r723000 CY) FWID 01-3b33decd
Aug 10 14:51:11 **** kernel: [ 23.947331] serial serial0: tty port ttySC0 registered
Aug 10 14:51:11 **** kernel: [ 23.948372] serial serial1: tty port ttySC1 registered
Aug 10 14:51:11 **** rng-tools[283]: Starting Hardware RNG entropy gatherer daemon: rngd.
Aug 10 14:51:11 **** rngd[299]: rngd 2-unofficial-mt.14 starting up…
Aug 10 14:51:11 **** thd[290]: Found socket passed from systemd
Aug 10 14:51:11 **** systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)…
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
Aug 10 14:51:11 **** systemd[1]: Starting Configure Bluetooth Modems connected by UART…
Aug 10 14:51:11 **** systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped.
Aug 10 14:51:11 **** rngd[299]: entropy feed to the kernel ready
Aug 10 14:51:11 **** systemd[1]: Started Manage Sound Card State (restore and store).
Aug 10 14:51:11 **** systemd[1]: Starting Save/Restore Sound Card State…
Aug 10 14:51:11 **** alsactl[314]: alsactl 1.1.8 daemon started
Aug 10 14:51:11 **** systemd[1]: Started D-Bus System Message Bus.
Aug 10 14:51:12 **** systemd[1]: Starting Avahi mDNS/DNS-SD Stack…
Aug 10 14:51:12 **** systemd[1]: Starting WPA supplicant…
Aug 10 14:51:12 **** systemd[1]: Starting Check for v3d driver…
Aug 10 14:51:12 **** avahi-daemon[340]: Found user ‘avahi’ (UID 108) and group ‘avahi’ (GID 113).
Aug 10 14:51:12 **** avahi-daemon[340]: Successfully dropped root privileges.
Aug 10 14:51:12 **** avahi-daemon[340]: avahi-daemon 0.7 starting up.
Aug 10 14:51:12 **** systemd[1]: Started CANDY RED Gateway Service, version:9.3.0.
Aug 10 14:51:12 **** dphys-swapfile[279]: want /var/swap=100MByte, checking existing: keeping it
Aug 10 14:51:12 **** systemd[1]: Starting Login Service…
Aug 10 14:51:12 **** kernel: [ 26.660312] uart-pl011 20201000.serial: no DMA platform data
Aug 10 14:51:12 **** systemd[1]: Started System Logging Service.
Aug 10 14:51:12 **** systemd[1]: Started triggerhappy global hotkey daemon.
Aug 10 14:51:12 **** systemd[1]: Started Raise network interfaces.
Aug 10 14:51:12 **** root: Activating Bluetooth…
Aug 10 14:51:13 **** start_systemd.sh[356]: <13>Aug 10 14:51:12 root: Activating Bluetooth…
Aug 10 14:51:13 **** avahi-daemon[340]: Successfully called chroot().
Aug 10 14:51:13 **** avahi-daemon[340]: Successfully dropped remaining capabilities.
Aug 10 14:51:13 **** systemd[1]: Started rng-tools.service.
Aug 10 14:51:13 **** avahi-daemon[340]: No service file found in /etc/avahi/services.
Aug 10 14:51:13 **** avahi-daemon[340]: Network interface enumeration completed.
Aug 10 14:51:13 **** avahi-daemon[340]: Server startup complete. Host name is **.local. Local service cookie is 1059564086.
Aug 10 14:51:13 **** wpa_supplicant[345]: Successfully initialized wpa_supplicant
Aug 10 14:51:13 **** systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Aug 10 14:51:13 **** systemd[1]: pppd-dns.service: Succeeded.
Aug 10 14:51:13 **** systemd[1]: Started Restore /etc/resolv.conf if the system crashed before the ppp link was shut down.
Aug 10 14:51:13 **** systemd[1]: Started Save/Restore Sound Card State.
Aug 10 14:51:13 **** rfkill: unblock set for type bluetooth
Aug 10 14:51:13 **** systemd[1]: Started Check for v3d driver.
Aug 10 14:51:13 **** kernel: [ 27.468507] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS
Aug 10 14:51:13 **** systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file.
Aug 10 14:51:13 **** kernel: [ 27.763259] Bluetooth: Core ver 2.22
Aug 10 14:51:13 **** kernel: [ 27.763412] NET: Registered protocol family 31
Aug 10 14:51:13 **** kernel: [ 27.763427] Bluetooth: HCI device and connection manager initialized
Aug 10 14:51:13 **** kernel: [ 27.763465] Bluetooth: HCI socket layer initialized
Aug 10 14:51:13 **** kernel: [ 27.763489] Bluetooth: L2CAP socket layer initialized
Aug 10 14:51:13 **** kernel: [ 27.763539] Bluetooth: SCO socket layer initialized
Aug 10 14:51:13 **** start_systemd.sh[356]: Can’t get device info: No such device
Aug 10 14:51:13 **** systemd[1]: Reached target Sound Card.
Aug 10 14:51:13 **** systemd[1]: Started WPA supplicant.
Aug 10 14:51:13 **** systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Aug 10 14:51:14 **** systemd[1]: Started Login Service.
Aug 10 14:51:14 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:14 **** raspi-config[304]: Checking if shift key is held down:Error opening '/dev/input/event
’: No such file or directory
Aug 10 14:51:14 **** systemd[1]: Starting dhcpcd on all interfaces…
Aug 10 14:51:14 **** raspi-config[304]: No. Switching to ondemand scaling governor.
Aug 10 14:51:14 **** systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Aug 10 14:51:14 **** root: node options => --max-old-space-size=144
Aug 10 14:51:14 **** start_systemd.sh[356]: <13>Aug 10 14:51:14 root: node options => --max-old-space-size=144
Aug 10 14:51:14 **** dhcpcd[392]: dev: loaded udev
Aug 10 14:51:14 **** root: Starting candy-red…
Aug 10 14:51:14 **** kernel: [ 28.703722] 8021q: 802.1Q VLAN Support v1.8
Aug 10 14:51:14 **** start_systemd.sh[356]: <13>Aug 10 14:51:14 root: Starting candy-red…
Aug 10 14:51:14 **** dhcpcd[392]: forked to background, child pid 403
Aug 10 14:51:14 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:51:15 **** systemd[1]: systemd-rfkill.service: Succeeded.
Aug 10 14:51:15 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:51:15 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:51:15 **** systemd[1]: Started dhcpcd on all interfaces.
Aug 10 14:51:15 **** dhcpcd-run-hooks[414]: wlan0: starting wpa_supplicant
Aug 10 14:51:15 **** systemd[1]: Reached target Network.
Aug 10 14:51:15 **** systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server…
Aug 10 14:51:15 **** systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator…
Aug 10 14:51:15 **** systemd[1]: Starting OpenBSD Secure Shell server…
Aug 10 14:51:15 **** dnsmasq[416]: dnsmasq: syntax check OK.
Aug 10 14:51:15 **** systemd[1]: Starting Permit User Sessions…
Aug 10 14:51:15 **** systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Aug 10 14:51:15 **** systemd[1]: Starting vsftpd FTP server…
Aug 10 14:51:15 **** systemd[1]: Reached target Network is Online.
Aug 10 14:51:15 **** kernel: [ 29.675059] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
Aug 10 14:51:15 **** hostapd[417]: Configuration file: /etc/hostapd/hostapd.conf
Aug 10 14:51:15 **** systemd[1]: Starting /etc/rc.local Compatibility…
Aug 10 14:51:15 **** hostapd[417]: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Aug 10 14:51:15 **** hostapd[417]: wlan0: Could not connect to kernel driver
Aug 10 14:51:15 **** hostapd[417]: Using interface wlan0 with hwaddr b8:27:eb:20:25:6f and ssid “AgriSSID”
Aug 10 14:51:15 **** systemd[1]: Starting Samba NMB Daemon…
Aug 10 14:51:16 **** systemd[1]: Started vsftpd FTP server.
Aug 10 14:51:16 **** systemd[1]: Started Permit User Sessions.
Aug 10 14:51:16 **** hostapd[417]: wlan0: interface state COUNTRY_UPDATE->ENABLED
Aug 10 14:51:16 **** kernel: [ 30.758598] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Aug 10 14:51:16 **** hostapd[417]: wlan0: AP-ENABLED
Aug 10 14:51:16 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:51:16 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 1.
Aug 10 14:51:16 **** systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator.
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: connected to Access Point `’
Aug 10 14:51:17 **** kernel: [ 31.060453] Bluetooth: HCI UART driver ver 2.3
Aug 10 14:51:17 **** kernel: [ 31.060477] Bluetooth: HCI UART protocol H4 registered
Aug 10 14:51:17 **** kernel: [ 31.060612] Bluetooth: HCI UART protocol Three-wire (H5) registered
Aug 10 14:51:17 **** kernel: [ 31.060952] Bluetooth: HCI UART protocol Broadcom registered
Aug 10 14:51:17 **** btuart[308]: bcm43xx_init
Aug 10 14:51:17 **** btuart[308]: Flash firmware /lib/firmware/brcm/BCM43430A1.hcd
Aug 10 14:51:17 **** btuart[308]: Set BDADDR UART: b8:27:eb:df:da:90
Aug 10 14:51:17 **** btuart[308]: Set Controller UART speed to 3000000 bit/s
Aug 10 14:51:17 **** btuart[308]: Device setup complete
Aug 10 14:51:17 **** systemd[1]: Started Configure Bluetooth Modems connected by UART.
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: waiting for carrier
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: carrier acquired
Aug 10 14:51:17 **** dhcpcd[403]: DUID 00:01:00:01:25:1e:c7:2f:b8:27:eb:20:25:6f
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: IAID eb:20:25:6f
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: adding address fe80::5857:c295:1403:5e7
Aug 10 14:51:17 **** avahi-daemon[340]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::5857:c295:1403:5e7.
Aug 10 14:51:17 **** avahi-daemon[340]: New relevant interface wlan0.IPv6 for mDNS.
Aug 10 14:51:17 **** avahi-daemon[340]: Registering new address record for fe80::5857:c295:1403:5e7 on wlan0.
.
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: probing address 192.168.22.1/24
Aug 10 14:51:17 **** dhcpcd[403]: wlan0: carrier lost
Aug 10 14:51:18 **** dnsmasq[468]: started, version 2.80 cachesize 150
Aug 10 14:51:18 **** dnsmasq[468]: compile time options: IPv6 GNU-getopt DBus i18n IDN DHCP DHCPv6 no-Lua TFTP conntrack ipset auth DNSSEC loop-detect inotify dumpfile
Aug 10 14:51:18 **** dnsmasq-dhcp[468]: DHCP, IP range 192.168.22.10 – 192.168.22.40, lease time 1d
Aug 10 14:51:18 **** dnsmasq[468]: read /etc/hosts - 5 addresses

※ログ最後

Aug 10 14:51:18 **** dhcpcd[403]: wlan0: deleting address fe80::5857:c295:1403:5e7
Aug 10 14:51:18 **** avahi-daemon[340]: Withdrawing address record for fe80::5857:c295:1403:5e7 on wlan0.
Aug 10 14:51:18 **** avahi-daemon[340]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::5857:c295:1403:5e7.
Aug 10 14:51:18 **** avahi-daemon[340]: Interface wlan0.IPv6 no longer relevant for mDNS.
Aug 10 14:51:18 **** systemd[1]: Started OpenBSD Secure Shell server.
Aug 10 14:51:18 **** systemd[1]: Starting Bluetooth service…
Aug 10 14:51:18 **** systemd[1]: Created slice system-bthelper.slice.
Aug 10 14:51:18 **** dhcpcd[403]: wlan0: carrier acquired
Aug 10 14:51:18 **** systemd[1]: Starting Load/Save RF Kill Switch Status…
Aug 10 14:51:18 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:18 **** dhcpcd[403]: wlan0: IAID eb:20:25:6f
Aug 10 14:51:18 **** dhcpcd[403]: wlan0: adding address fe80::5857:c295:1403:5e7
Aug 10 14:51:19 **** avahi-daemon[340]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::5857:c295:1403:5e7.
Aug 10 14:51:19 **** avahi-daemon[340]: New relevant interface wlan0.IPv6 for mDNS.
Aug 10 14:51:19 **** avahi-daemon[340]: Registering new address record for fe80::5857:c295:1403:5e7 on wlan0.*.
Aug 10 14:51:19 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:19 **** dhcpcd[403]: wlan0: probing address 192.168.22.1/24
Aug 10 14:51:19 **** dhcpcd[403]: wlan0: soliciting an IPv6 router
Aug 10 14:51:19 **** systemd[1]: Started /etc/rc.local Compatibility.
Aug 10 14:51:19 **** systemd[1]: Started Load/Save RF Kill Switch Status.
Aug 10 14:51:19 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:51:20 **** systemd[1]: Starting Hold until boot process finishes up…
Aug 10 14:51:20 **** systemd[1]: Starting Terminate Plymouth Boot Screen…
Aug 10 14:51:20 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:51:20 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:51:20 **** systemd[1]: plymouth-start.service: Succeeded.
Aug 10 14:51:20 **** systemd[1]: plymouth-quit-wait.service: Succeeded.
Aug 10 14:51:20 **** systemd[1]: Started Hold until boot process finishes up.
Aug 10 14:51:20 **** systemd[1]: plymouth-quit.service: Succeeded.
Aug 10 14:51:20 **** systemd[1]: Started Terminate Plymouth Boot Screen.
Aug 10 14:51:20 **** systemd[1]: Received SIGRTMIN+21 from PID 113 (n/a).
Aug 10 14:51:20 **** systemd[1]: Received SIGRTMIN+21 from PID 113 (n/a).
Aug 10 14:51:20 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:51:20 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 2.
Aug 10 14:51:20 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:20 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:20 **** systemd[1]: Started Getty on tty1.
Aug 10 14:51:20 **** systemd[1]: Reached target Login Prompts.
Aug 10 14:51:20 **** bluetoothd[480]: Bluetooth daemon 5.50
Aug 10 14:51:20 **** systemd[1]: Started Bluetooth service.
Aug 10 14:51:20 **** bluetoothd[480]: Starting SDP server
Aug 10 14:51:21 **** systemd[1]: Started Raspberry Pi bluetooth helper.
Aug 10 14:51:21 **** systemd[1]: Reached target Bluetooth.
Aug 10 14:51:21 **** systemd[1]: Started BluezALSA proxy.
Aug 10 14:51:21 **** kernel: [ 35.176131] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Aug 10 14:51:21 **** kernel: [ 35.176150] Bluetooth: BNEP filters: protocol multicast
Aug 10 14:51:21 **** kernel: [ 35.176182] Bluetooth: BNEP socket layer initialized
Aug 10 14:51:21 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:51:21 **** bluetoothd[480]: Bluetooth management interface 1.14 initialized
Aug 10 14:51:21 **** bluetoothd[480]: Sap driver initialization failed.
Aug 10 14:51:21 **** dbus-daemon[323]: [system] Activating via systemd: service name=‘org.freedesktop.hostname1’ unit=‘dbus-org.freedesktop.hostname1.service’ requested by ‘:1.4’ (uid=0 pid=480 comm="/usr/lib/bluetooth/bluetoothd ")
Aug 10 14:51:21 **** bluetoothd[480]: sap-server: Operation not permitted (1)
Aug 10 14:51:21 **** dnsmasq[468]: no servers found in /run/dnsmasq/resolv.conf, will retry
Aug 10 14:51:21 **** bluetoothd[480]: Failed to set privacy: Rejected (0x0b)
Aug 10 14:51:21 **** bthelper[519]: Raspberry Pi BDADDR already set
Aug 10 14:51:21 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:51:21 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:51:21 **** bluetoothd[480]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/Source/1
Aug 10 14:51:21 **** bluetoothd[480]: Endpoint registered: sender=:1.6 path=/org/bluez/hci0/A2DP/SBC/Source/2
Aug 10 14:51:21 **** systemd[1]: Starting Hostname Service…
Aug 10 14:51:21 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:51:21 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 3.
Aug 10 14:51:22 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:22 **** kernel: [ 36.065324] Bluetooth: RFCOMM TTY layer initialized
Aug 10 14:51:22 **** kernel: [ 36.065366] Bluetooth: RFCOMM socket layer initialized
Aug 10 14:51:22 **** kernel: [ 36.065420] Bluetooth: RFCOMM ver 1.11
Aug 10 14:51:22 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:22 **** dnsmasq[475]: Too few arguments.
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001112-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000111f-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 Class: 0x00480000
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001112-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 UUIDs: 0000111f-0000-1000-8000-00805f9b34fb
Aug 10 14:51:22 **** bthelper[519]: Changing power off succeeded
Aug 10 14:51:22 **** systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server.
Aug 10 14:51:22 **** systemd[1]: Reached target Host and Network Name Lookups.
Aug 10 14:51:22 **** systemd[1]: Started Python Program port_surveillance.py.
Aug 10 14:51:22 **** systemd[1]: Started Python Program mqtt_subscriber.py.
Aug 10 14:51:22 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:51:22 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:51:22 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:51:23 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:51:23 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 4.
Aug 10 14:51:23 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:23 **** systemd[1]: Started CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:23 **** bthelper[519]: [#033[0;93mCHG#033[0m] Controller B8:27:EB:DF:DA:90 Class: 0x00480000
Aug 10 14:51:23 **** bthelper[519]: Changing power on succeeded
Aug 10 14:51:23 **** systemd[1]: bthelper@hci0.service: Succeeded.
Aug 10 14:51:23 **** dhcpcd[403]: wlan0: using static address 192.168.22.1/24
Aug 10 14:51:23 **** avahi-daemon[340]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.22.1.
Aug 10 14:51:23 **** dbus-daemon[323]: [system] Successfully activated service ‘org.freedesktop.hostname1’
Aug 10 14:51:23 **** systemd[1]: Started Hostname Service.
Aug 10 14:51:23 **** dhcpcd[403]: wlan0: adding route to 192.168.22.0/24
Aug 10 14:51:23 **** dhcpcd[403]: wlan0: adding default route via 192.168.22.1
Aug 10 14:51:23 **** avahi-daemon[340]: New relevant interface wlan0.IPv4 for mDNS.
Aug 10 14:51:23 **** avahi-daemon[340]: Registering new address record for 192.168.22.1 on wlan0.IPv4.
Aug 10 14:51:23 **** candy-pi-lite: [ERROR] Modem is missing
Aug 10 14:51:23 **** systemd[1]: candy-pi-lite.service: Main process exited, code=exited, status=11/n/a
Aug 10 14:51:23 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:51:23 **** systemd[1]: candy-pi-lite.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:51:23 **** systemd[1]: candy-pi-lite.service: Scheduled restart job, restart counter is at 5.
Aug 10 14:51:24 **** systemd[1]: Stopped CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:24 **** systemd[1]: candy-pi-lite.service: Start request repeated too quickly.
Aug 10 14:51:24 **** systemd[1]: candy-pi-lite.service: Failed with result ‘exit-code’.
Aug 10 14:51:24 **** systemd[1]: Failed to start CANDY Pi Lite Service, version:7.1.1.
Aug 10 14:51:24 **** dnsmasq[468]: reading /run/dnsmasq/resolv.conf
Aug 10 14:51:24 **** dnsmasq[468]: ignoring nameserver 192.168.22.1 - local interface
Aug 10 14:51:24 **** systemd[1]: systemd-rfkill.service: Succeeded.
Aug 10 14:51:27 **** systemd[1]: Started Samba NMB Daemon.
Aug 10 14:51:27 **** systemd[1]: Starting Samba SMB Daemon…
Aug 10 14:51:30 **** systemd[1]: Started Samba SMB Daemon.
Aug 10 14:51:30 **** systemd[1]: Reached target Multi-User System.
Aug 10 14:51:30 **** systemd[1]: Starting Update UTMP about System Runlevel Changes…
Aug 10 14:51:31 **** systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Aug 10 14:51:31 **** systemd[1]: Started Update UTMP about System Runlevel Changes.
Aug 10 14:51:31 **** systemd[1]: Startup finished in 3.912s (kernel) + 41.169s (userspace) = 45.082s.
Aug 10 14:51:32 **** dhcpcd[403]: wlan0: no IPv6 Routers available
Aug 10 14:51:37 **** systemd[1]: systemd-fsckd.service: Succeeded.
Aug 10 14:51:53 **** systemd[1]: systemd-hostnamed.service: Succeeded.
Aug 10 14:51:54 **** start_systemd.sh[356]: [CANDY RED] Using PAM for authentication
Aug 10 14:51:56 **** start_systemd.sh[356]: 10 Aug 14:51:55 - [info] [CANDY RED] Headless Enabled? => false
Aug 10 14:51:56 **** start_systemd.sh[356]: 10 Aug 14:51:56 - [info] [CANDY RED] Deploying Flow Editor UI…
Aug 10 14:51:57 **** start_systemd.sh[356]: 10 Aug 14:51:57 - [info]
Aug 10 14:51:57 **** start_systemd.sh[356]: Welcome to Node-RED
Aug 10 14:51:57 **** start_systemd.sh[356]: ===================
Aug 10 14:51:57 **** start_systemd.sh[356]: 10 Aug 14:51:57 - [info] Node-RED バージョン: v1.0.5 [candy-red v9.3.0]
Aug 10 14:51:57 **** start_systemd.sh[356]: 10 Aug 14:51:57 - [info] Node.js バージョン: v10.21.0
Aug 10 14:51:57 **** start_systemd.sh[356]: 10 Aug 14:51:57 - [info] Linux 5.4.51+ arm LE
Aug 10 14:52:15 **** start_systemd.sh[356]: 10 Aug 14:52:15 - [info] パレットノードのロード
(省略)
Aug 10 14:52:29 **** mqtt_subscriber.sh[563]: socket.gaierror: [Errno -3] Temporary failure in name resolution
Aug 10 14:52:30 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:52:30 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:52:30 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:52:30 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 1.
Aug 10 14:52:30 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:52:30 **** systemd[1]: Started Python Program mqtt_subscriber.py.
Aug 10 14:52:50 **** start_systemd.sh[356]: 10 Aug 14:52:50 - [info] Worldmap version 2.3.6
Aug 10 14:52:57 **** start_systemd.sh[356]: 10 Aug 14:52:57 - [info] Dashboard version 2.20.0 started at /api/ui
Aug 10 14:53:07 **** start_systemd.sh[356]: 10 Aug 14:53:07 - [info] コンテキストストア : ‘default’ [module=memory]
Aug 10 14:53:07 **** start_systemd.sh[356]: 10 Aug 14:53:07 - [info] ユーザディレクトリ : /opt/candy-red/.node-red
Aug 10 14:53:07 **** start_systemd.sh[356]: 10 Aug 14:53:07 - [warn] プロジェクトは無効化されています : editorTheme.projects.enabled=false
Aug 10 14:53:07 **** start_systemd.sh[356]: 10 Aug 14:53:07 - [info] フローファイル : /opt/candy-red/.node-red/flows_candy-red.json
Aug 10 14:53:07 **** start_systemd.sh[356]: 10 Aug 14:53:07 - [warn]
Aug 10 14:53:07 **** start_systemd.sh[356]: ---------------------------------------------------------------------
Aug 10 14:53:07 **** start_systemd.sh[356]: フローのクレデンシャルファイルはシステム生成キーで暗号化されています。
Aug 10 14:53:07 **** start_systemd.sh[356]: システム生成キーを何らかの理由で失った場合、クレデンシャルファイルを
Aug 10 14:53:07 **** start_systemd.sh[356]: 復元することはできません。その場合、ファイルを削除してクレデンシャルを
Aug 10 14:53:07 **** start_systemd.sh[356]: 再入力しなければなりません。
Aug 10 14:53:07 **** start_systemd.sh[356]: 設定ファイル内で ‘credentialSecret’ オプションを使って独自キーを設定
Aug 10 14:53:07 **** start_systemd.sh[356]: します。変更を次にデプロイする際、Node-REDは選択したキーを用いてクレ
Aug 10 14:53:07 **** start_systemd.sh[356]: デンシャルを再暗号化します。
Aug 10 14:53:07 **** start_systemd.sh[356]: ---------------------------------------------------------------------
Aug 10 14:53:07 **** start_systemd.sh[356]: 10 Aug 14:53:07 - [info] [GenericBLE] Start BLE scanning
Aug 10 14:53:08 **** start_systemd.sh[356]: 10 Aug 14:53:08 - [info] フローを開始します
Aug 10 14:53:08 **** start_systemd.sh[356]: 10 Aug 14:53:08 - [info] [inject:89c364b0.763c98] repeat = 1000
Aug 10 14:53:09 **** start_systemd.sh[356]: 10 Aug 14:53:09 - [info] [CANDY RED] Listen port=8100
Aug 10 14:53:32 **** mqtt_subscriber.sh[659]: [2020-08-10 14:53:32,170] [mqtt_subscriber.py.root] [298] [DEBUG] ports_out: [1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16]
Aug 10 14:53:32 **** mqtt_subscriber.sh[659]: [2020-08-10 14:53:32,177] [control.py.root] [33] [INFO] init() Start
Aug 10 14:53:32 **** kernel: [ 166.806046] usb usb1-port1: disabled by hub (EMI?), re-enabling…
Aug 10 14:53:32 **** kernel: [ 166.806081] usb 1-1: USB disconnect, device number 2
Aug 10 14:53:32 **** kernel: [ 166.810331] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
Aug 10 14:53:32 **** kernel: [ 166.810509] ftdi_sio 1-1:1.0: device disconnected
Aug 10 14:53:32 **** mqtt_subscriber.sh[659]: [2020-08-10 14:53:32,888] [control.py.root] [84] [INFO] init() End
Aug 10 14:53:32 **** mqtt_subscriber.sh[659]: [2020-08-10 14:53:32,893] [mqtt_subscriber.py.root] [117] [INFO] main() Start
Aug 10 14:53:32 **** mqtt_subscriber.sh[659]: [2020-08-10 14:53:32,913] [mqtt_subscriber.py.root] [164] [INFO] connect() Start
Aug 10 14:53:33 **** kernel: [ 167.006064] Indeed it is in host mode hprt0 = 00021501
(省略)
Aug 10 14:53:33 **** mqtt_subscriber.sh[659]: socket.gaierror: [Errno -3] Temporary failure in name resolution
Aug 10 14:53:33 **** kernel: [ 167.386016] usb 1-1: new full-speed USB device number 3 using dwc_otg
Aug 10 14:53:33 **** kernel: [ 167.386297] Indeed it is in host mode hprt0 = 00021501
Aug 10 14:53:33 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:53:33 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:53:33 **** kernel: [ 167.701865] usb 1-1: New USB device found, idVendor=0403, idProduct=6001, bcdDevice= 6.00
Aug 10 14:53:33 **** kernel: [ 167.701891] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Aug 10 14:53:33 **** kernel: [ 167.701904] usb 1-1: Product: USB-RS485 Cable
Aug 10 14:53:33 **** kernel: [ 167.701916] usb 1-1: Manufacturer: FTDI
Aug 10 14:53:33 **** kernel: [ 167.701927] usb 1-1: SerialNumber: FT42I08Y
Aug 10 14:53:33 **** kernel: [ 167.714715] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
Aug 10 14:53:33 **** kernel: [ 167.714980] usb 1-1: Detected FT232RL
Aug 10 14:53:33 **** kernel: [ 167.717910] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB0
Aug 10 14:53:33 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:53:33 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 2.
Aug 10 14:53:33 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:53:33 **** systemd[1]: Started Python Program mqtt_subscriber.py.
Aug 10 14:53:33 **** mtp-probe: checking bus 1, device 3: “/sys/devices/platform/soc/20980000.usb/usb1/1-1”
Aug 10 14:53:33 **** mtp-probe: bus: 1, device: 3 was not an MTP device
Aug 10 14:53:34 **** mtp-probe: checking bus 1, device 3: “/sys/devices/platform/soc/20980000.usb/usb1/1-1”
Aug 10 14:53:34 **** mtp-probe: bus: 1, device: 3 was not an MTP device
Aug 10 14:53:40 **** hostapd: wlan0: STA fc:77:74:23:ec:4f IEEE 802.11: associated
Aug 10 14:53:40 **** hostapd: wlan0: STA fc:77:74:23:ec:4f RADIUS: starting accounting session DFCB9DD01B94D342
Aug 10 14:53:40 **** hostapd: wlan0: STA fc:77:74:23:ec:4f WPA: pairwise key handshake completed (RSN)
Aug 10 14:53:40 **** dnsmasq-dhcp[468]: DHCPREQUEST(wlan0) 192.168.22.39 fc:77:74:23:ec:4f
Aug 10 14:53:40 **** dnsmasq-dhcp[468]: DHCPACK(wlan0) 192.168.22.39 fc:77:74:23:ec:4f 2F-HAYASHI-NOTE
(省略)
Aug 10 14:54:36 **** mqtt_subscriber.sh[704]: socket.gaierror: [Errno -3] Temporary failure in name resolution
Aug 10 14:54:36 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=exited, status=1/FAILURE
Aug 10 14:54:36 **** systemd[1]: mqtt_subscriber.service: Failed with result ‘exit-code’.
Aug 10 14:54:37 **** systemd[1]: mqtt_subscriber.service: Service RestartSec=100ms expired, scheduling restart.
Aug 10 14:54:37 **** systemd[1]: mqtt_subscriber.service: Scheduled restart job, restart counter is at 3.
Aug 10 14:54:37 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:54:37 **** systemd[1]: Started Python Program mqtt_subscriber.py.
Aug 10 14:55:08 **** systemd[1]: Stopping Python Program mqtt_subscriber.py…
Aug 10 14:55:08 **** systemd[1]: mqtt_subscriber.service: Main process exited, code=killed, status=15/TERM
Aug 10 14:55:08 **** systemd[1]: mqtt_subscriber.service: Succeeded.
Aug 10 14:55:08 **** systemd[1]: Stopped Python Program mqtt_subscriber.py.
Aug 10 14:55:42 **** hostapd: wlan0: STA 80:38:96:e9:2a:07 IEEE 802.11: associated
Aug 10 14:55:42 **** hostapd: wlan0: STA 80:38:96:e9:2a:07 RADIUS: starting accounting session 190B6ED6327253AE
Aug 10 14:55:42 **** hostapd: wlan0: STA 80:38:96:e9:2a:07 WPA: pairwise key handshake completed (RSN)
Aug 10 14:55:42 **** dnsmasq-dhcp[468]: DHCPDISCOVER(wlan0) 80:38:96:e9:2a:07
Aug 10 14:55:42 **** dnsmasq-dhcp[468]: DHCPOFFER(wlan0) 192.168.22.35 80:38:96:e9:2a:07
Aug 10 14:55:42 **** dnsmasq-dhcp[468]: DHCPREQUEST(wlan0) 192.168.22.35 80:38:96:e9:2a:07
Aug 10 14:55:42 **** dnsmasq-dhcp[468]: DHCPACK(wlan0) 192.168.22.35 80:38:96:e9:2a:07
Aug 10 14:56:49 **** dbus-daemon[323]: [system] Activating via systemd: service name=‘org.freedesktop.hostname1’ unit=‘dbus-org.freedesktop.hostname1.service’ requested by ‘:1.15’ (uid=0 pid=981 comm="systemd-analyze plot ")
Aug 10 14:56:49 **** systemd[1]: Starting Hostname Service…
Aug 10 14:56:49 **** dbus-daemon[323]: [system] Successfully activated service ‘org.freedesktop.hostname1’
Aug 10 14:56:49 **** systemd[1]: Started Hostname Service.
Aug 10 14:57:19 **** systemd[1]: systemd-hostnamed.service: Succeeded.

ありがとうございます。

ログを確認する限り、CANDY Pi Liteが起動しない直接の原因は

[ERROR] Modem is missing

とあることから、CANDY Pi Liteの通信モジュールの状態に関係があると思われます。

可能性としては、電力不足によって通信モジュールが停止またはリセットなど不安定な状態になっていることが考えられます。

次のような方法によって電力供給を増やすことをご検討の上お試しいただけますでしょうか。

  1. ラズパイゼロに電力を供給している場合、3AのmicroUSB用のACアダプターをご検討いただく(ラズパイ向けの電源アダプターとして販売されているもの)。
  2. CANDY Pi Liteへの電力供給へ切り替えて、4AのACアダプターをご検討いただく(DCジャックの規格はこちら)をご覧ください。

また、可能なタイミングで最新のOSおよびCANDY Pi Liteソフトウェアに更新していただけますと幸いです。

ご確認ください。

回答ありがとうございます。
電源はTDK Lambda DSP60-5 を使用しており、供給電力としては十分だと思われます。
改めて現象としては
1.インターネットによる外部接続が出来なくなり、現地に行く。
2.WiFiルータ機能が生きている時には、wifi接続する。WiFiルータ機能が死んでいる時もあり、その時は電源を切って再起動する。
3.wifi接続できた際に、sudo candy service restart でインターネット接続が出来るときもあれば、何度やっても接続できない時もある。
4.接続できない場合、シャットダウンしてセットアップ直後のmicroSDカードに変えて再起動すると、インターネットに接続して問題なく使用できる。

現象がその時によりまちまちなのですが、何か考えられる原因は有りますでしょうか。
ログを送るときにどのようなキーワードで場所を特定すれば良いかなどアドバイスをお願いします。

ご返信ありがとうございます。

こちらは、GPIOピンへの給電でしょうか?
データシートによりますと7A供給とのことですがCANDY Pi LiteのDCジャック経由では4Aまでの供給上限としておりますので念のため確認です。

こちらについて、OS再起動の場合(コマンドラインからsudo rebootを実行した場合)は、接続するか分かりますか?

なお、ログについてはキーワードだけでは特定しにくいため、時間帯で切り取っていただく形で、Started CANDY Pi Lite Service, version:から始まる文字列から、以下のような記述があるところまでの間となります(バージョンが異なるため、厳密には表記が少し違うかもしれませんが大体以下と同じようになっています)。

→正常動作の場合のログの終わり(日時表記を削除しています)

[candy-pi-lite] server_main.<module>: [NOTICE] <candy-pi-lite> serial_port:/dev/ttySC1 (460800 bps), nic:ppp0
[candy-pi-lite] server_main.__init__: [NOTICE] <candy-pi-lite> RESTART_SCHEDULE_CRON=>[] is ignored
[candy-pi-lite] server_main.run: [NOTICE] <candy-pi-lite> Button Extension is terminated.

→異常動作時の場合のログの終わり(日時表記を削除しています)

systemd[1]: Stopping CANDY Pi Lite Service, version:

これまでの情報から、通信モジュール側がなんらかの理由で応答しなくなり、その結果接続が切れて、通信モジュールとのやり取りができなくなりCANDY Pi Liteサービスが停止していると推測しています。

通信モジュールが自動復帰するエラーなのかどうかが残念ながらはっきりしませんが、もし自動復帰する場合は、CANDY Pi Liteサービス側のリトライにより復帰できるようになると思います。
が、こちらで全く同じ状況を常に再現できる可能性はあまりないため、これでうまく行けるかどうかは申し上げられないのですが、そう言った対応について調査・対策を進めます。

なお、もし対応した場合は、CANDY Pi Liteサービスを最新版にしていただくことが必要となります(方法はリリース時にご案内いたします)。

ログにつきまして、追記いたします。
最新バージョンでは、CANDY Pi Liteサービスのログにcandy-pi-liteのラベルが付いていますのでそれをキーワードにすることが可能です。合わせて関連するラベルとしてはpppdがありますのでその2つで抽出していただくと関連するログを得ることができます。

以下が、LTE-M版ではなくてマルチキャリア版になってしまいますが抽出した場合の例となります(時間などは削除しています)。
なお、現在お使いの7.1.1ではキーワードが設定されていないため、アップデート後にご確認いただければと思います。

candy-pi-lite: [INFO] Initializing CANDY Pi Lite Board...
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 115200...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 460800...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 115200...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 460800...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 115200...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 460800...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 115200...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 460800...
candy-pi-lite: [INFO] Result: None
candy-pi-lite: [INFO] Looking for a Modem Serial port at Barudrate: 115200...
candy-pi-lite: [INFO] Result: /dev/ttySC1
candy-pi-lite: [INFO] Modem Serial port: /dev/ttySC1 and AT Serial port: /dev/ttySC1 are selected
candy-pi-lite: [INFO] Initializing modem with baudrate:460800
candy-pi-lite: [INFO] Modem baudrate changed: 115200 => 460800
candy-pi-lite: [INFO] Initialization Done. Modem Serial Port => /dev/ttySC1 Modem baudrate => 460800
candy-pi-lite: [INFO] SIM card state => SIM_STATE_READY
candy-pi-lite: [INFO] EC25 Phone Functionality => Full
candy-pi-lite: [INFO] Saved APN => my-apn
candy-pi-lite: [INFO] Operator => N/A
candy-pi-lite: [INFO] Waiting for network registration => Status:Searching
candy-pi-lite: [INFO] Operator => N/A
candy-pi-lite: [INFO] Waiting for network registration => Status:Searching
candy-pi-lite: [INFO] Operator => N/A
candy-pi-lite: [INFO] Waiting for network registration => Status:Searching
candy-pi-lite: [INFO] Operator => N/A
candy-pi-lite: [INFO] Waiting for network registration => Status:Searching
candy-pi-lite: [INFO] Operator => N/A
candy-pi-lite: [INFO] OK. Registered in the home ps network
candy-pi-lite: [INFO] Module Model: EC25
candy-pi-lite: [INFO] Network Timezone: 9.0
candy-pi-lite: [INFO] Skipped to adjust time
candy-pi-lite: [INFO] Trying to establish a connection...
candy-pi-lite: [INFO] Trying to connect...(Trial:1/3, Timeout:5sec)
candy-pi-lite: [INFO] Starting PPP: /dev/ttySC1
pppd[24420]: pppd 2.4.7 started by root, uid 0
pppd[24420]: Serial connection established.
pppd[24420]: Using interface ppp0
pppd[24420]: Connect: ppp0 <--> /dev/ttySC1
pppd[24420]: CHAP authentication succeeded
pppd[24420]: CHAP authentication succeeded
candy-pi-lite: [ERROR] PPP cannot be online
pppd[24420]: Terminating on signal 15
pppd[24420]: Connection terminated.
pppd[24420]: Serial link disconnected.
pppd[24420]: Modem hangup
pppd[24420]: Exit.
candy-pi-lite: [INFO] start_pppd.sh terminated: Exit Code => 16
candy-pi-lite: [INFO] Trying to connect...(Trial:2/3, Timeout:35sec)
candy-pi-lite: [INFO] Starting PPP: /dev/ttySC1
pppd[24507]: pppd 2.4.7 started by root, uid 0
pppd[24507]: Serial connection established.
pppd[24507]: Using interface ppp0
pppd[24507]: Connect: ppp0 <--> /dev/ttySC1
pppd[24507]: CHAP authentication succeeded
pppd[24507]: CHAP authentication succeeded
pppd[24507]: Could not determine remote IP address: defaulting to 123.123.123.123
pppd[24507]: local  IP address 123.123.123.123
pppd[24507]: remote IP address 123.123.123.123
pppd[24507]: primary   DNS address 123.123.123.123
pppd[24507]: secondary DNS address 123.123.123.123
candy-pi-lite: [INFO] PPP goes online
candy-pi-lite: [INFO] CANDY Pi Lite Board is initialized successfully!
[candy-pi-lite] server_main.<module>: [NOTICE] <candy-pi-lite> serial_port:/dev/ttySC1 (460800 bps), nic:ppp0
[candy-pi-lite] server_main.__init__: [NOTICE] <candy-pi-lite> RESTART_SCHEDULE_CRON=>[] is ignored
[candy-pi-lite] server_main.run: [NOTICE] <candy-pi-lite> Button Extension is terminated.

CANDY Pi Lite v10.2.0をリリース致しました。
ログメッセージなどを改善していますので、状況がもう少し詳しく見えるようになるかと思われます。

下記リンク先よりアップデートの手順をご確認ください。
お手数をおかけしますがよろしくお願いいたします。