電源投入後ONLINEにならない。


#1

お世話になっております。

Candy Pi liteを下記機器構成で使用したおりますが、2度電源投入時に”ONLINE"にならない事象が発生いたしました。通常は、数分で”ONLINE"になりますが、上記時には、10分以上待ちましたが"ONLINE"にならず強制的にリセットいたしました。
原因として考えられることがあるでしょうか??

また、長時間通信を行わない場合、"ONLINE"が切れることも発生しておりますが、これは、SORACOM側の問題でしょうか??

機器構成等は、
Raspberry pi ----- Raspberry Pi 2 model B
midcroSD ------ 16GB(class 10)
CANDY Pi ------ CANDY Pi Lite(LTE)
OS ----- raspberry pi専用OSイメージファイル(Ver 5.2)
SIM ------ SORACOM plan-D
接続方法 ------ GPIO

考えられる対策等あればご教示ください。
よろしくお願いいたします。


#2

ご質問ありがとうございます。
確認させていただきたいのですが、

2度電源投入時に”ONLINE"にならない事象

とは、一度電源を落として、電源を再度入れた時に通信ができなくなるということでよろしいでしょうか?
また、以下可能な範囲で教えていただけますでしょうか?

  • 事象が発生した時の/var/log/syslogのログ(該当部分だけで構いません)
  • 事象が発生した場所でのsudo candy network showの結果

また、長時間通信を行わない場合、"ONLINE"が切れることも発生しておりますが、これは、SORACOM側の問題でしょうか??

接続を確立した状態で無通信状態のまま一定時間経過すると、網側(ドコモもしくは、SORACOMなどMVNOの設備側)で切断されます。網側の動作仕様と思われます。
CANDY Pi Liteのソフトウェアでは、上記の切断時や、あるいは移動時の圏外切断からの圏内復帰時に再接続するような仕組みを入れておりますので、圏内であれば再接続されるようになります。

上記情報をいただけますと幸いです。よろしくお願いいたします。


#3

ご回答誠にありがとうございます。

事象の発生は、長時間通信を行わない状況により、”OFFLINE"になったため電源を入れなおした状況で発生したようです。

該当機器は、客先に導入済みでデータを送信しない旨の連絡があり、ネットワークの状況(Candy Pi 黄色LEDの点滅)確認をいていただきましたところ"OFFLINE"であったため電源を落とし再度通電したところ発生したとのことです。
logなどは、手元に機器が無いためすぐにお知らせすることが出来ません。(キーボードなどを接続していないブラックボックスとして導入いたしたおりますので、客先での対応は無理のようで、また、発生日時等も正確には記憶していないとのことですので・・・)

必要な情報をお伝え出来す誠に申し訳ありません。
よろしくお願いいたします。


#4

状況承知いたしました。
ログを確認するまでは断定できませんが、以下の点ご確認いただければと思います。

  1. 電波をつかめていないまたはSIMが外れている
  2. SORACOM Air回線の状態変更

前者は、例えば、

  • アンテナとCANDY Pi Liteをつなぐコネクターが緩んで外れかけている、あるいは外れている
  • 設置場所を移動して圏外あるいは電波の弱いエリアになった
  • SIMが外れている

といったものです。

後者はSORACOM Air SIMを管理するコンソールで間違えて回線を停止していないかご確認いただければと思います。また当該コンソールでは接続の履歴(セッション履歴)を見ることができますので、ご確認いただければと思います。


#5

お世話になっております。

問題の再現のため、客先より機器を引き上げテストいたしましたところ、再現出来ましたのでLogをお送りいたします。(どの部分をお送りすればよいか不明ですので該当すると思われれるところを抜粋します。)

電源投入後autostartにより、自動で制御プログラムを起動させ、そのプログラムの冒頭で”ONLINE”をコマンド(sudo candy connection statsu コマンド) で確認しています。(”ONLINE"になるまでループ)

/var/log/syslog より抜粋
Mar 2 16:52:13 raspberrypi candy-pi-lite: [INFO] start_pppd.sh terminated: Exit Code => 16
Mar 2 16:52:14 raspberrypi candy-pi-lite: [INFO] CANDY Pi Lite Board is initialized successfully!
Mar 2 16:52:14 raspberrypi server_main.: [NOTICE] serial_port:/dev/ttySC1 (460800 bps), nic:ppp0
Mar 2 16:52:14 raspberrypi server_main.init: [NOTICE] RESTART_SCHEDULE_CRON=>[] is ignored
Mar 2 16:52:16 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:18 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:20 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:23 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:25 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:27 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:29 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:32 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:34 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:36 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established
Mar 2 16:52:39 raspberrypi candy-pi-lite: [OFFLINE] The connection is not established

このLogが延々と出力されております。

この後、強制的に制御プログラムを停止して5分ほど待ちましたがやはり”ONLINE"になりませんでした、
そこで、”suspend” → ”resume” コマンドにより”ONLINE"に移行できることを確認いたしました。

よろしくお願いいたします。


#6

ご連絡ありがとうございます。

ログにつきまして、「Mar 2 16:52:13」より前のログもご提示いただけますでしょうか?具体的には「systemd[1]: Started CANDY Pi Lite Service, version:<バージョン番号>.」などと出ている部分以降のものです。

また、「 [OFFLINE] The connection is not established」については、「sudo candy connection status」コマンドの実行結果として表示されたログとなります。

お手数をおかけしますが、よろしくお願いいたします。


#7

お世話になっております。
ご依頼のLogをごご連絡いたします。
字数制限を超えてしまいますので2度に分けてお送りいたします。
よろしくお願いいたします。

Mar 2 16:47:35 raspberrypi systemd[1]: Started CANDY Pi Lite Service, version:6.2.0.
Mar 2 16:47:35 raspberrypi kernel: [ 0.255130] vc-sm: Videocore shared memory driver
Mar 2 16:47:35 raspberrypi kernel: [ 0.255396] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
Mar 2 16:47:35 raspberrypi kernel: [ 0.265059] brd: module loaded
Mar 2 16:47:35 raspberrypi kernel: [ 0.273980] loop: module loaded
Mar 2 16:47:35 raspberrypi kernel: [ 0.273995] Loading iSCSI transport class v2.0-870.
Mar 2 16:47:35 raspberrypi systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)…
Mar 2 16:47:35 raspberrypi kernel: [ 0.274688] libphy: Fixed MDIO Bus: probed
Mar 2 16:47:35 raspberrypi kernel: [ 0.274799] usbcore: registered new interface driver lan78xx
Mar 2 16:47:35 raspberrypi systemd[1]: Started CUPS Scheduler.
Mar 2 16:47:35 raspberrypi kernel: [ 0.274853] usbcore: registered new interface driver smsc95xx
Mar 2 16:47:35 raspberrypi kernel: [ 0.274868] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
Mar 2 16:47:35 raspberrypi kernel: [ 0.302776] dwc_otg 3f980000.usb: base=0xf0980000
Mar 2 16:47:35 raspberrypi kernel: [ 0.503010] Core Release: 2.80a
Mar 2 16:47:35 raspberrypi kernel: [ 0.503019] Setting default values for core params
Mar 2 16:47:35 raspberrypi systemd[1]: Starting Save/Restore Sound Card State…
Mar 2 16:47:35 raspberrypi kernel: [ 0.503048] Finished setting default values for core params
Mar 2 16:47:35 raspberrypi kernel: [ 0.703291] Using Buffer DMA mode
Mar 2 16:47:35 raspberrypi kernel: [ 0.703297] Periodic Transfer Interrupt Enhancement - disabled
Mar 2 16:47:35 raspberrypi systemd[1]: Started Regular background program processing daemon.
Mar 2 16:47:35 raspberrypi kernel: [ 0.703301] Multiprocessor Interrupt Enhancement - disabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.703308] OTG VER PARAM: 0, OTG VER FLAG: 0
Mar 2 16:47:35 raspberrypi kernel: [ 0.703318] Dedicated Tx FIFOs mode
Mar 2 16:47:35 raspberrypi systemd[1]: Starting System Logging Service…
Mar 2 16:47:35 raspberrypi kernel: [ 0.703702] WARN::dwc_otg_hcd_init:1046: FIQ DMA bounce buffers: virt = 0xbb914000 dma = 0xfb914000 len=9024
Mar 2 16:47:35 raspberrypi kernel: [ 0.703726] FIQ FSM acceleration enabled for :
Mar 2 16:47:35 raspberrypi kernel: [ 0.703726] Non-periodic Split Transactions
Mar 2 16:47:35 raspberrypi cron[359]: (CRON) INFO (pidfile fd = 3)
Mar 2 16:47:35 raspberrypi kernel: [ 0.703726] Periodic Split Transactions
Mar 2 16:47:35 raspberrypi kernel: [ 0.703726] High-Speed Isochronous Endpoints
Mar 2 16:47:35 raspberrypi systemd[1]: Started CANDY RED Gateway Service, version:8.1.0.
Mar 2 16:47:35 raspberrypi kernel: [ 0.703726] Interrupt/Control Split Transaction hack enabled
Mar 2 16:47:35 raspberrypi systemd[1]: Started ShutDown Daemon.
Mar 2 16:47:35 raspberrypi kernel: [ 0.703734] dwc_otg: Microframe scheduler enabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.703787] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x805ea470
Mar 2 16:47:35 raspberrypi systemd[1]: Starting LSB: Autogenerate and use a swap file…
Mar 2 16:47:35 raspberrypi kernel: [ 0.703798] WARN::hcd_init_fiq:460: FIQ ASM at 0x805ea7d8 length 36
Mar 2 16:47:35 raspberrypi kernel: [ 0.703810] WARN::hcd_init_fiq:486: MPHI regs_base at 0xf0006000
Mar 2 16:47:35 raspberrypi kernel: [ 0.703863] dwc_otg 3f980000.usb: DWC OTG Controller
Mar 2 16:47:35 raspberrypi systemd[1]: Starting Restore /etc/resolv.conf if the system crashed before the ppp link was shut down…
Mar 2 16:47:35 raspberrypi kernel: [ 0.703895] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
Mar 2 16:47:35 raspberrypi kernel: [ 0.703927] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
Mar 2 16:47:35 raspberrypi systemd[1]: Starting triggerhappy global hotkey daemon…
Mar 2 16:47:35 raspberrypi kernel: [ 0.703975] Init: Port Power? op_state=1
Mar 2 16:47:35 raspberrypi kernel: [ 0.703980] Init: Power Port (0)
Mar 2 16:47:35 raspberrypi systemd[1]: Starting Disable WiFi if country not set…
Mar 2 16:47:35 raspberrypi kernel: [ 0.704184] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
Mar 2 16:47:35 raspberrypi kernel: [ 0.704195] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Mar 2 16:47:35 raspberrypi kernel: [ 0.704203] usb usb1: Product: DWC OTG Controller
Mar 2 16:47:35 raspberrypi kernel: [ 0.704212] usb usb1: Manufacturer: Linux 4.14.79-v7+ dwc_otg_hcd
Mar 2 16:47:35 raspberrypi cron[359]: (CRON) INFO (Running @reboot jobs)
Mar 2 16:47:35 raspberrypi kernel: [ 0.704220] usb usb1: SerialNumber: 3f980000.usb
Mar 2 16:47:35 raspberrypi kernel: [ 0.704834] hub 1-0:1.0: USB hub found
Mar 2 16:47:35 raspberrypi kernel: [ 0.704873] hub 1-0:1.0: 1 port detected
Mar 2 16:47:35 raspberrypi systemd[1]: Starting dhcpcd on all interfaces…
Mar 2 16:47:35 raspberrypi kernel: [ 0.705369] dwc_otg: FIQ enabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.705375] dwc_otg: NAK holdoff enabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.705379] dwc_otg: FIQ split-transaction FSM enabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.705389] Module dwc_common_port init
Mar 2 16:47:35 raspberrypi kernel: [ 0.705638] usbcore: registered new interface driver usb-storage
Mar 2 16:47:35 raspberrypi systemd[1]: Started D-Bus System Message Bus.
Mar 2 16:47:35 raspberrypi kernel: [ 0.705826] mousedev: PS/2 mouse device common for all mice
Mar 2 16:47:35 raspberrypi kernel: [ 0.705901] IR NEC protocol handler initialized
Mar 2 16:47:35 raspberrypi kernel: [ 0.705906] IR RC5(x/sz) protocol handler initialized
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: Found user ‘avahi’ (UID 108) and group ‘avahi’ (GID 112).
Mar 2 16:47:35 raspberrypi kernel: [ 0.705912] IR RC6 protocol handler initialized
Mar 2 16:47:35 raspberrypi kernel: [ 0.705917] IR JVC protocol handler initialized
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: Successfully dropped root privileges.
Mar 2 16:47:35 raspberrypi kernel: [ 0.705921] IR Sony protocol handler initialized
Mar 2 16:47:35 raspberrypi kernel: [ 0.705928] IR SANYO protocol handler initialized
Mar 2 16:47:35 raspberrypi kernel: [ 0.705933] IR Sharp protocol handler initialized
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: avahi-daemon 0.6.32 starting up.
Mar 2 16:47:35 raspberrypi kernel: [ 0.705938] IR MCE Keyboard/mouse protocol handler initialized
Mar 2 16:47:35 raspberrypi thd[365]: Found socket passed from systemd
Mar 2 16:47:35 raspberrypi kernel: [ 0.705943] IR XMP protocol handler initialized
Mar 2 16:47:35 raspberrypi root: Activating Bluetooth…
Mar 2 16:47:35 raspberrypi kernel: [ 0.706627] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
Mar 2 16:47:35 raspberrypi kernel: [ 0.706890] bcm2835-cpufreq: min=600000 max=900000
Mar 2 16:47:35 raspberrypi kernel: [ 0.707247] sdhci: Secure Digital Host Controller Interface driver
Mar 2 16:47:35 raspberrypi start_systemd.sh[361]: <13>Mar 2 16:47:34 root: Activating Bluetooth…
Mar 2 16:47:35 raspberrypi kernel: [ 0.707252] sdhci: Copyright© Pierre Ossman
Mar 2 16:47:35 raspberrypi kernel: [ 0.707607] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
Mar 2 16:47:35 raspberrypi kernel: [ 0.707712] sdhci-pltfm: SDHCI platform and OF driver helper
Mar 2 16:47:35 raspberrypi start_systemd.sh[361]: Can’t open RFKILL control device: No such file or directory
Mar 2 16:47:35 raspberrypi kernel: [ 0.708264] ledtrig-cpu: registered to indicate activity on CPUs
Mar 2 16:47:35 raspberrypi kernel: [ 0.708365] hidraw: raw HID events driver © Jiri Kosina
Mar 2 16:47:35 raspberrypi dhcpcd[368]: dev: loaded udev
Mar 2 16:47:35 raspberrypi kernel: [ 0.708506] usbcore: registered new interface driver usbhid
Mar 2 16:47:35 raspberrypi kernel: [ 0.708510] usbhid: USB HID core driver
Mar 2 16:47:35 raspberrypi kernel: [ 0.709134] vchiq: vchiq_init_state: slot_zero = bb980000, is_master = 0
Mar 2 16:47:35 raspberrypi liblogging-stdlog: [origin software=“rsyslogd” swVersion=“8.24.0” x-pid=“360” x-info=“http://www.rsyslog.com”] start
Mar 2 16:47:35 raspberrypi kernel: [ 0.710681] [vc_sm_connected_init]: start
Mar 2 16:47:35 raspberrypi kernel: [ 0.720415] [vc_sm_connected_init]: end - returning 0
Mar 2 16:47:35 raspberrypi kernel: [ 0.721042] Initializing XFRM netlink socket
Mar 2 16:47:35 raspberrypi kernel: [ 0.721067] NET: Registered protocol family 17
Mar 2 16:47:35 raspberrypi kernel: [ 0.721163] Key type dns_resolver registered
Mar 2 16:47:35 raspberrypi kernel: [ 0.721720] Registering SWP/SWPB emulation handler
Mar 2 16:47:35 raspberrypi kernel: [ 0.722312] registered taskstats version 1
Mar 2 16:47:35 raspberrypi kernel: [ 0.728214] uart-pl011 3f201000.serial: cts_event_workaround enabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.728286] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
Mar 2 16:47:35 raspberrypi kernel: [ 0.728338] console [ttyAMA0] enabled
Mar 2 16:47:35 raspberrypi kernel: [ 0.730283] sdhost: log_buf @ bb913000 (fb913000)
Mar 2 16:47:35 raspberrypi kernel: [ 0.811521] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Mar 2 16:47:35 raspberrypi kernel: [ 0.812538] of_cfs_init
Mar 2 16:47:35 raspberrypi kernel: [ 0.812631] of_cfs_init: OK
Mar 2 16:47:35 raspberrypi kernel: [ 0.813206] Waiting for root device PARTUUID=34cd5140-02…
Mar 2 16:47:35 raspberrypi kernel: [ 0.878777] mmc0: host does not support reading read-only switch, assuming write-enable
Mar 2 16:47:35 raspberrypi kernel: [ 0.881249] mmc0: new high speed SDHC card at address 59b4
Mar 2 16:47:35 raspberrypi kernel: [ 0.881802] mmcblk0: mmc0:59b4 SDU1 14.6 GiB
Mar 2 16:47:35 raspberrypi kernel: [ 0.883252] mmcblk0: p1 p2
Mar 2 16:47:35 raspberrypi kernel: [ 0.912466] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Mar 2 16:47:35 raspberrypi kernel: [ 0.912519] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Mar 2 16:47:35 raspberrypi kernel: [ 0.920542] devtmpfs: mounted
Mar 2 16:47:35 raspberrypi kernel: [ 0.922407] Indeed it is in host mode hprt0 = 00021501
Mar 2 16:47:35 raspberrypi kernel: [ 0.933145] Freeing unused kernel memory: 1024K
Mar 2 16:47:35 raspberrypi kernel: [ 1.007633] random: fast init done
Mar 2 16:47:35 raspberrypi kernel: [ 1.131548] usb 1-1: new high-speed USB device number 2 using dwc_otg
Mar 2 16:47:35 raspberrypi kernel: [ 1.131697] Indeed it is in host mode hprt0 = 00001101
Mar 2 16:47:35 raspberrypi kernel: [ 1.371809] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
Mar 2 16:47:35 raspberrypi kernel: [ 1.371825] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Mar 2 16:47:35 raspberrypi kernel: [ 1.372496] hub 1-1:1.0: USB hub found
Mar 2 16:47:35 raspberrypi kernel: [ 1.372587] hub 1-1:1.0: 5 ports detected
Mar 2 16:47:35 raspberrypi kernel: [ 1.543494] NET: Registered protocol family 10
Mar 2 16:47:35 raspberrypi kernel: [ 1.544587] Segment Routing with IPv6
Mar 2 16:47:35 raspberrypi kernel: [ 1.554100] ip_tables: © 2000-2006 Netfilter Core Team
Mar 2 16:47:35 raspberrypi kernel: [ 1.573412] random: systemd: uninitialized urandom read (16 bytes read)
Mar 2 16:47:35 raspberrypi kernel: [ 1.615840] random: systemd: uninitialized urandom read (16 bytes read)
Mar 2 16:47:35 raspberrypi kernel: [ 1.633989] uart-pl011 3f201000.serial: no DMA platform data
Mar 2 16:47:35 raspberrypi kernel: [ 1.647131] random: systemd-gpt-aut: uninitialized urandom read (16 bytes read)
Mar 2 16:47:35 raspberrypi kernel: [ 1.701566] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
Mar 2 16:47:35 raspberrypi kernel: [ 1.831881] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
Mar 2 16:47:35 raspberrypi kernel: [ 1.831898] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Mar 2 16:47:35 raspberrypi kernel: [ 1.834601] smsc95xx v1.0.6
Mar 2 16:47:35 raspberrypi kernel: [ 1.945202] smsc95xx 1-1.1:1.0 eth0: register ‘smsc95xx’ at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:ae:12:1f
Mar 2 16:47:35 raspberrypi kernel: [ 2.041563] usb 1-1.2: new high-speed USB device number 4 using dwc_otg
Mar 2 16:47:35 raspberrypi kernel: [ 2.173063] usb 1-1.2: New USB device found, idVendor=05e3, idProduct=0608
Mar 2 16:47:35 raspberrypi kernel: [ 2.173085] usb 1-1.2: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Mar 2 16:47:35 raspberrypi kernel: [ 2.173093] usb 1-1.2: Product: USB2.0 Hub
Mar 2 16:47:35 raspberrypi kernel: [ 2.174291] hub 1-1.2:1.0: USB hub found
Mar 2 16:47:35 raspberrypi kernel: [ 2.174696] hub 1-1.2:1.0: 4 ports detected
Mar 2 16:47:35 raspberrypi kernel: [ 2.271632] usb 1-1.3: new full-speed USB device number 5 using dwc_otg
Mar 2 16:47:35 raspberrypi kernel: [ 2.312017] i2c /dev entries driver
Mar 2 16:47:35 raspberrypi kernel: [ 2.429733] usb 1-1.3: New USB device found, idVendor=0403, idProduct=6001
Mar 2 16:47:35 raspberrypi kernel: [ 2.429752] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Mar 2 16:47:35 raspberrypi kernel: [ 2.429762] usb 1-1.3: Product: MONOSTICK
Mar 2 16:47:35 raspberrypi kernel: [ 2.429771] usb 1-1.3: Manufacturer: MONOWIRELESS
Mar 2 16:47:35 raspberrypi kernel: [ 2.429779] usb 1-1.3: SerialNumber: MW2YV5ZG
Mar 2 16:47:35 raspberrypi kernel: [ 2.501637] usb 1-1.2.2: new low-speed USB device number 6 using dwc_otg
Mar 2 16:47:35 raspberrypi kernel: [ 2.540586] nf_conntrack version 0.5.0 (15360 buckets, 61440 max)
Mar 2 16:47:35 raspberrypi kernel: [ 2.608552] ip6_tables: © 2000-2006 Netfilter Core Team
Mar 2 16:47:35 raspberrypi kernel: [ 2.652982] usb 1-1.2.2: New USB device found, idVendor=1c4f, idProduct=0002
Mar 2 16:47:35 raspberrypi kernel: [ 2.653001] usb 1-1.2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 2 16:47:35 raspberrypi kernel: [ 2.653011] usb 1-1.2.2: Product: USB Keyboard
Mar 2 16:47:35 raspberrypi kernel: [ 2.653021] usb 1-1.2.2: Manufacturer: SIGMACHIP
Mar 2 16:47:35 raspberrypi kernel: [ 2.661930] input: SIGMACHIP USB Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.2/1-1.2.2:1.0/0003:1C4F:0002.0001/input/input0
Mar 2 16:47:35 raspberrypi kernel: [ 2.742325] hid-generic 0003:1C4F:0002.0001: input,hidraw0: USB HID v1.10 Keyboard [SIGMACHIP USB Keyboard] on usb-3f980000.usb-1.2.2/input0
Mar 2 16:47:35 raspberrypi kernel: [ 2.752089] input: SIGMACHIP USB Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.2/1-1.2.2:1.1/0003:1C4F:0002.0002/input/input1
Mar 2 16:47:35 raspberrypi kernel: [ 2.768344] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Mar 2 16:47:35 raspberrypi kernel: [ 2.821913] hid-generic 0003:1C4F:0002.0002: input,hidraw1: USB HID v1.10 Device [SIGMACHIP USB Keyboard] on usb-3f980000.usb-1.2.2/input1
Mar 2 16:47:35 raspberrypi kernel: [ 2.921636] usb 1-1.2.3: new low-speed USB device number 7 using dwc_otg
Mar 2 16:47:35 raspberrypi kernel: [ 3.068631] usb 1-1.2.3: New USB device found, idVendor=056e, idProduct=0035
Mar 2 16:47:35 raspberrypi kernel: [ 3.068654] usb 1-1.2.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Mar 2 16:47:35 raspberrypi kernel: [ 3.068663] usb 1-1.2.3: Product: ELECOM USB mouse with wheel
Mar 2 16:47:35 raspberrypi kernel: [ 3.068672] usb 1-1.2.3: Manufacturer: ELECOM
Mar 2 16:47:35 raspberrypi kernel: [ 3.079067] input: ELECOM ELECOM USB mouse with wheel as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2.3/1-1.2.3:1.0/0003:056E:0035.0003/input/input2
Mar 2 16:47:35 raspberrypi kernel: [ 3.079490] hid-generic 0003:056E:0035.0003: input,hidraw2: USB HID v1.11 Mouse [ELECOM ELECOM USB mouse with wheel] on usb-3f980000.usb-1.2.3/input0
Mar 2 16:47:35 raspberrypi kernel: [ 3.236867] usbcore: registered new interface driver usbserial
Mar 2 16:47:35 raspberrypi kernel: [ 3.236948] usbcore: registered new interface driver usbserial_generic
Mar 2 16:47:35 raspberrypi kernel: [ 3.237006] usbserial: USB Serial support registered for generic
Mar 2 16:47:35 raspberrypi kernel: [ 3.251435] usbcore: registered new interface driver ftdi_sio
Mar 2 16:47:35 raspberrypi kernel: [ 3.251586] usbserial: USB Serial support registered for FTDI USB Serial Device
Mar 2 16:47:35 raspberrypi kernel: [ 3.251966] ftdi_sio 1-1.3:1.0: FTDI USB Serial Device converter detected
Mar 2 16:47:35 raspberrypi kernel: [ 3.254738] usb 1-1.3: Detected FT232RL
Mar 2 16:47:35 raspberrypi kernel: [ 3.257616] usb 1-1.3: FTDI USB Serial Device converter now attached to ttyUSB0
Mar 2 16:47:35 raspberrypi kernel: [ 3.829288] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
Mar 2 16:47:35 raspberrypi kernel: [ 3.844706] bcm2835_alsa bcm2835_alsa: card created with 8 channels
Mar 2 16:47:35 raspberrypi start_systemd.sh[361]: Can’t get device info: No such device
Mar 2 16:47:35 raspberrypi kernel: [ 8.696132] Bluetooth: Core ver 2.22
Mar 2 16:47:35 raspberrypi kernel: [ 8.696256] NET: Registered protocol family 31
Mar 2 16:47:35 raspberrypi kernel: [ 8.696298] Bluetooth: HCI device and connection manager initialized
Mar 2 16:47:35 raspberrypi kernel: [ 8.696322] Bluetooth: HCI socket layer initialized
Mar 2 16:47:35 raspberrypi kernel: [ 8.696337] Bluetooth: L2CAP socket layer initialized
Mar 2 16:47:35 raspberrypi kernel: [ 8.696372] Bluetooth: SCO socket layer initialized
Mar 2 16:47:35 raspberrypi root: node options => --max-old-space-size=313
Mar 2 16:47:35 raspberrypi start_systemd.sh[361]: <13>Mar 2 16:47:35 root: node options => --max-old-space-size=313
Mar 2 16:47:35 raspberrypi dhcpcd[368]: eth0: waiting for carrier
Mar 2 16:47:35 raspberrypi kernel: [ 9.033804] smsc95xx 1-1.1:1.0 eth0: hardware isn’t capable of remote wakeup
Mar 2 16:47:35 raspberrypi kernel: [ 9.034044] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: Successfully called chroot().
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: Successfully dropped remaining capabilities.
Mar 2 16:47:35 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Mar 2 16:47:35 raspberrypi systemd[1]: Started Make remote CUPS printers available locally.
Mar 2 16:47:35 raspberrypi systemd[1]: Starting Login Service…
Mar 2 16:47:35 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Mar 2 16:47:35 raspberrypi systemd[1]: Started System Logging Service.
Mar 2 16:47:35 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Mar 2 16:47:35 raspberrypi systemd[1]: Started Restore /etc/resolv.conf if the system crashed before the ppp link was shut down.
Mar 2 16:47:35 raspberrypi systemd[1]: Started Disable WiFi if country not set.
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: No service file found in /etc/avahi/services.
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: Network interface enumeration completed.
Mar 2 16:47:35 raspberrypi avahi-daemon[351]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 2462157070.
Mar 2 16:47:35 raspberrypi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
Mar 2 16:47:35 raspberrypi systemd[1]: Started Login Service.
Mar 2 16:47:36 raspberrypi candy-pi-lite: [INFO] Initializing CANDY Pi Lite Board…
Mar 2 16:47:36 raspberrypi root: Starting candy-red…
Mar 2 16:47:36 raspberrypi start_systemd.sh[361]: <13>Mar 2 16:47:36 root: Starting candy-red…
Mar 2 16:47:37 raspberrypi dphys-swapfile[363]: Starting dphys-swapfile swapfile setup …
Mar 2 16:47:37 raspberrypi systemd[1]: Started Raise network interfaces.
Mar 2 16:47:37 raspberrypi dphys-swapfile[363]: want /var/swap=100MByte, checking existing: keeping it
Mar 2 16:47:37 raspberrypi kernel: [ 10.707958] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS
Mar 2 16:47:37 raspberrypi dphys-swapfile[363]: done.
Mar 2 16:47:37 raspberrypi systemd[1]: Started LSB: Autogenerate and use a swap file.
Mar 2 16:47:37 raspberrypi kernel: [ 11.184338] random: crng init done
Mar 2 16:47:37 raspberrypi kernel: [ 11.184355] random: 7 urandom warning(s) missed due to ratelimiting
Mar 2 16:47:38 raspberrypi raspi-config[353]: Checking if shift key is held down: No. Switching to ondemand scaling governor.
Mar 2 16:47:38 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Mar 2 16:47:45 raspberrypi start_systemd.sh[361]: [INFO] Using PAM for authentication
Mar 2 16:47:45 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:45 - [info] [CANDY RED] flowFileSignature: 8c1b25f75780a535c9464d18f21b747183104be6
Mar 2 16:47:45 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:45 - [info] [CANDY RED] Deploying Flow Editor UI…
Mar 2 16:47:46 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:46 - [info]
Mar 2 16:47:46 raspberrypi start_systemd.sh[361]: Welcome to Node-RED
Mar 2 16:47:46 raspberrypi start_systemd.sh[361]: ===================
Mar 2 16:47:46 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:46 - [info] Node-RED version: v0.18.7 [candy-red v8.1.0]
Mar 2 16:47:46 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:46 - [info] Node.js version: v8.12.0
Mar 2 16:47:46 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:46 - [info] Linux 4.14.79-v7+ arm LE
Mar 2 16:47:47 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:47 - [info] Loading palette nodes
Mar 2 16:47:48 raspberrypi candy-pi-lite: [INFO] Modem Serial port: /dev/ttySC1 and AT Serial port: /dev/ttySC1 are selected
Mar 2 16:47:49 raspberrypi candy-pi-lite: [INFO] Initializing modem with baudrate:460800
Mar 2 16:47:50 raspberrypi candy-pi-lite: [INFO] Modem baudrate changed: 115200 => 460800
Mar 2 16:47:50 raspberrypi candy-pi-lite: [INFO] Initialization Done. Modem Serial Port => /dev/ttySC1 Modem baudrate => 460800
Mar 2 16:47:51 raspberrypi candy-pi-lite: [INFO] SIM card state => SIM_STATE_READY
Mar 2 16:47:51 raspberrypi dbus[370]: [system] Activating via systemd: service name=‘org.freedesktop.timedate1’ unit=‘dbus-org.freedesktop.timedate1.service’
Mar 2 16:47:51 raspberrypi systemd[1]: Starting Time & Date Service…
Mar 2 16:47:51 raspberrypi dbus[370]: [system] Successfully activated service ‘org.freedesktop.timedate1’
Mar 2 16:47:51 raspberrypi systemd[1]: Started Time & Date Service.
Mar 2 16:47:54 raspberrypi candy-pi-lite: [INFO] Phone Functionality => Full
Mar 2 16:47:54 raspberrypi candy-pi-lite: [INFO] Saved APN => soracom.io
Mar 2 16:47:55 raspberrypi candy-pi-lite: [INFO] Operator => NTT DOCOMO NTT DOCOMO
Mar 2 16:47:55 raspberrypi start_systemd.sh[361]: 2 Mar 16:47:55 - [info] Dashboard version 2.10.1 started at /api/ui
Mar 2 16:47:55 raspberrypi candy-pi-lite: [INFO] OK. Registered in the home ps network
Mar 2 16:47:56 raspberrypi candy-pi-lite: [INFO] Module Model: EC21
Mar 2 16:47:56 raspberrypi candy-pi-lite: [INFO] Network Timezone: 9.0

以上(1/2)。


#8

お世話になっております。
残り1/2をお送りいたします。

Mar 2 16:48:13 raspberrypi start_systemd.sh[352]: 2019年 3月 2日 土曜日 16:48:13 JST
Mar 2 16:48:13 raspberrypi systemd[1]: Time has been changed
Mar 2 16:48:13 raspberrypi systemd[1]: apt-daily.timer: Adding 7h 57min 53.355643s random time.
Mar 2 16:48:13 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 2min 49.968018s random time.
Mar 2 16:48:13 raspberrypi candy-pi-lite: [INFO] Adjusted the current time => 19/03/02,07:48:12 UTC
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] User directory : /opt/candy-red/.node-red
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [warn] Projects disabled : editorTheme.projects.enabled=false
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] Flows file : /opt/candy-red/.node-red/flows_candy-red.json
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [warn]
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: ---------------------------------------------------------------------
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: Your flow credentials file is encrypted using a system-generated key.
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: If the system-generated key is lost for any reason, your credentials
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: file will not be recoverable, you will have to delete it and re-enter
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: your credentials.
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: You should set your own key using the ‘credentialSecret’ option in
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: your settings file. Node-RED will then re-encrypt your credentials
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: file using your chosen key the next time you deploy a change.
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: ---------------------------------------------------------------------
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] [GenericBLE] Start BLE scanning
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] Starting flows
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] [inject:89c364b0.763c98] repeat = 1000
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] [GenericBLE] Start BLE scanning
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] Started flows
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] Listen port=8100
Mar 2 16:48:13 raspberrypi start_systemd.sh[361]: 2 Mar 16:48:13 - [info] CANDY Pi Lite GNSS Client is disabled
Mar 2 16:48:14 raspberrypi candy-pi-lite: [INFO] Trying to establish a connection…
Mar 2 16:48:14 raspberrypi start_systemd.sh[352]: RTNETLINK answers: No such process
Mar 2 16:48:14 raspberrypi candy-pi-lite: [INFO] Trying to connect…(Trial:1/3)
Mar 2 16:48:14 raspberrypi candy-pi-lite: [INFO] Starting PPP: /dev/ttySC1
Mar 2 16:48:14 raspberrypi pppd[640]: pppd 2.4.7 started by root, uid 0
Mar 2 16:48:14 raspberrypi kernel: [ 31.557293] PPP generic driver version 2.4.2
Mar 2 16:48:15 raspberrypi pppd[640]: Serial connection established.
Mar 2 16:48:15 raspberrypi pppd[640]: Using interface ppp0
Mar 2 16:48:15 raspberrypi pppd[640]: Connect: ppp0 <–> /dev/ttySC1
Mar 2 16:48:16 raspberrypi pppd[640]: CHAP authentication succeeded
Mar 2 16:48:16 raspberrypi pppd[640]: CHAP authentication succeeded
Mar 2 16:48:21 raspberrypi dhcpcd[368]: timed out
Mar 2 16:48:21 raspberrypi dhcpcd[368]: forked to background, child pid 706
Mar 2 16:48:21 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Mar 2 16:48:21 raspberrypi systemd[1]: Reached target Network.
Mar 2 16:48:21 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server…
Mar 2 16:48:21 raspberrypi systemd[1]: Starting Permit User Sessions…
Mar 2 16:48:21 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility…
Mar 2 16:48:21 raspberrypi systemd[1]: Started Permit User Sessions.
Mar 2 16:48:21 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Mar 2 16:48:21 raspberrypi systemd[1]: Starting Light Display Manager…
Mar 2 16:48:21 raspberrypi systemd[1]: Starting Terminate Plymouth Boot Screen…
Mar 2 16:48:21 raspberrypi systemd[1]: Starting Hold until boot process finishes up…
Mar 2 16:48:21 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 178 (plymouthd).
Mar 2 16:48:21 raspberrypi systemd[1]: Started Terminate Plymouth Boot Screen.
Mar 2 16:48:21 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Mar 2 16:48:21 raspberrypi systemd[1]: Started Getty on tty1.
Mar 2 16:48:21 raspberrypi systemd[1]: Started Serial Getty on ttyAMA0.
Mar 2 16:48:21 raspberrypi systemd[1]: Reached target Login Prompts.
Mar 2 16:48:21 raspberrypi lightdm[718]: 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 2 16:48:21 raspberrypi systemd[1]: Started Light Display Manager.
Mar 2 16:48:22 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Mar 2 16:48:24 raspberrypi lightdm[763]: 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 2 16:48:24 raspberrypi systemd[1]: Created slice User Slice of pi.
Mar 2 16:48:24 raspberrypi systemd[1]: Starting User Manager for UID 1000…
Mar 2 16:48:24 raspberrypi systemd[1]: Started Session c1 of user pi.
Mar 2 16:48:24 raspberrypi systemd[777]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Mar 2 16:48:24 raspberrypi systemd[777]: Reached target Timers.
Mar 2 16:48:24 raspberrypi systemd[777]: Starting D-Bus User Message Bus Socket.
Mar 2 16:48:24 raspberrypi systemd[777]: Reached target Paths.
Mar 2 16:48:24 raspberrypi systemd[777]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Mar 2 16:48:24 raspberrypi systemd[777]: Listening on GnuPG cryptographic agent (access for web browsers).
Mar 2 16:48:24 raspberrypi systemd[777]: Listening on GnuPG cryptographic agent and passphrase cache.
Mar 2 16:48:24 raspberrypi systemd[777]: Listening on D-Bus User Message Bus Socket.
Mar 2 16:48:24 raspberrypi systemd[777]: Reached target Sockets.
Mar 2 16:48:24 raspberrypi systemd[777]: Reached target Basic System.
Mar 2 16:48:24 raspberrypi systemd[777]: Reached target Default.
Mar 2 16:48:24 raspberrypi systemd[777]: Startup finished in 139ms.
Mar 2 16:48:24 raspberrypi systemd[1]: Started User Manager for UID 1000.
Mar 2 16:48:24 raspberrypi lightdm[718]: Error opening audit socket: Protocol not supported
Mar 2 16:48:24 raspberrypi systemd[777]: Started D-Bus User Message Bus.
Mar 2 16:48:26 raspberrypi systemd[1]: Started Session c2 of user pi.
Mar 2 16:48:26 raspberrypi dbus-daemon[795]: Activating via systemd: service name=‘org.gtk.vfs.Daemon’ unit=‘gvfs-daemon.service’
Mar 2 16:48:26 raspberrypi systemd[777]: Starting Virtual filesystem service…
Mar 2 16:48:27 raspberrypi dbus-daemon[795]: Successfully activated service ‘org.gtk.vfs.Daemon’
Mar 2 16:48:27 raspberrypi systemd[777]: Started Virtual filesystem service.
Mar 2 16:48:27 raspberrypi kernel: [ 44.454501] fuse init (API version 7.26)
Mar 2 16:48:27 raspberrypi systemd[1]: Mounting FUSE Control File System…
Mar 2 16:48:27 raspberrypi systemd[1]: Mounted FUSE Control File System.
Mar 2 16:48:27 raspberrypi dbus-daemon[795]: Activating service name=‘ca.desrt.dconf’
Mar 2 16:48:28 raspberrypi dbus-daemon[795]: Successfully activated service ‘ca.desrt.dconf’
Mar 2 16:48:29 raspberrypi org.a11y.atspi.Registry[932]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
Mar 2 16:48:29 raspberrypi dbus-daemon[795]: Activating via systemd: service name=‘org.gtk.vfs.UDisks2VolumeMonitor’ unit=‘gvfs-udisks2-volume-monitor.service’
Mar 2 16:48:29 raspberrypi systemd[777]: Starting Virtual filesystem service - disk device monitor…
Mar 2 16:48:29 raspberrypi dbus[370]: [system] Activating via systemd: service name=‘org.freedesktop.UDisks2’ unit=‘udisks2.service’
Mar 2 16:48:29 raspberrypi systemd[1]: Starting Disk Manager…
Mar 2 16:48:29 raspberrypi udisksd[1006]: udisks daemon version 2.1.8 starting
Mar 2 16:48:29 raspberrypi dbus[370]: [system] Activating via systemd: service name=‘org.freedesktop.PolicyKit1’ unit=‘polkit.service’
Mar 2 16:48:29 raspberrypi systemd[1]: Starting Authorization Manager…
Mar 2 16:48:29 raspberrypi polkitd[1010]: started daemon version 0.105 using authority implementation local' version0.105’
Mar 2 16:48:29 raspberrypi dbus[370]: [system] Successfully activated service ‘org.freedesktop.PolicyKit1’
Mar 2 16:48:29 raspberrypi systemd[1]: Started Authorization Manager.
Mar 2 16:48:29 raspberrypi dbus[370]: [system] Successfully activated service ‘org.freedesktop.UDisks2’
Mar 2 16:48:29 raspberrypi systemd[1]: Started Disk Manager.
Mar 2 16:48:29 raspberrypi udisksd[1006]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Mar 2 16:48:29 raspberrypi dbus-daemon[795]: Successfully activated service ‘org.gtk.vfs.UDisks2VolumeMonitor’
Mar 2 16:48:29 raspberrypi systemd[777]: Started Virtual filesystem service - disk device monitor.
Mar 2 16:48:29 raspberrypi dbus-daemon[795]: Activating via systemd: service name=‘org.gtk.vfs.MTPVolumeMonitor’ unit=‘gvfs-mtp-volume-monitor.service’
Mar 2 16:48:29 raspberrypi systemd[777]: Starting Virtual filesystem service - Media Transfer Protocol monitor…
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Successfully activated service ‘org.gtk.vfs.MTPVolumeMonitor’
Mar 2 16:48:30 raspberrypi systemd[777]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Activating via systemd: service name=‘org.gtk.vfs.GoaVolumeMonitor’ unit=‘gvfs-goa-volume-monitor.service’
Mar 2 16:48:30 raspberrypi systemd[777]: Starting Virtual filesystem service - GNOME Online Accounts monitor…
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Successfully activated service ‘org.gtk.vfs.GoaVolumeMonitor’
Mar 2 16:48:30 raspberrypi systemd[777]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Activating via systemd: service name=‘org.gtk.vfs.AfcVolumeMonitor’ unit=‘gvfs-afc-volume-monitor.service’
Mar 2 16:48:30 raspberrypi systemd[777]: Starting Virtual filesystem service - Apple File Conduit monitor…
Mar 2 16:48:30 raspberrypi gvfs-afc-volume-monitor[1027]: Volume monitor alive
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Successfully activated service ‘org.gtk.vfs.AfcVolumeMonitor’
Mar 2 16:48:30 raspberrypi systemd[777]: Started Virtual filesystem service - Apple File Conduit monitor.
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Activating via systemd: service name=‘org.gtk.vfs.GPhoto2VolumeMonitor’ unit=‘gvfs-gphoto2-volume-monitor.service’
Mar 2 16:48:30 raspberrypi systemd[777]: Starting Virtual filesystem service - digital camera monitor…
Mar 2 16:48:30 raspberrypi dbus-daemon[795]: Successfully activated service ‘org.gtk.vfs.GPhoto2VolumeMonitor’
Mar 2 16:48:30 raspberrypi systemd[777]: Started Virtual filesystem service - digital camera monitor.
Mar 2 16:49:15 raspberrypi systemd[1]: dev-serial1.device: Job dev-serial1.device/start timed out.
Mar 2 16:49:15 raspberrypi systemd[1]: Timed out waiting for device dev-serial1.device.
Mar 2 16:49:15 raspberrypi systemd[1]: Dependency failed for Configure Bluetooth Modems connected by UART.
Mar 2 16:49:15 raspberrypi systemd[1]: hciuart.service: Job hciuart.service/start failed with result ‘dependency’.
Mar 2 16:49:15 raspberrypi systemd[1]: dev-serial1.device: Job dev-serial1.device/start failed with result ‘timeout’.
Mar 2 16:49:15 raspberrypi systemd[1]: Reached target Multi-User System.
Mar 2 16:49:15 raspberrypi systemd[1]: Reached target Graphical Interface.
Mar 2 16:49:15 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes…
Mar 2 16:49:15 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Mar 2 16:49:15 raspberrypi systemd[1]: Startup finished in 1.373s (kernel) + 1min 31.009s (userspace) = 1min 32.382s.
Mar 2 16:49:25 raspberrypi candy-pi-lite: [ERROR] PPP cannot be online
Mar 2 16:49:26 raspberrypi pppd[640]: Terminating on signal 15
Mar 2 16:49:32 raspberrypi pppd[640]: Connection terminated.
Mar 2 16:49:32 raspberrypi pppd[640]: Serial link disconnected.
Mar 2 16:49:33 raspberrypi pppd[640]: Modem hangup
Mar 2 16:49:33 raspberrypi pppd[640]: Exit.
Mar 2 16:49:33 raspberrypi candy-pi-lite: [INFO] start_pppd.sh terminated: Exit Code => 16
Mar 2 16:49:34 raspberrypi candy-pi-lite: [INFO] Trying to connect…(Trial:2/3)
Mar 2 16:49:34 raspberrypi candy-pi-lite: [INFO] Starting PPP: /dev/ttySC1
Mar 2 16:49:34 raspberrypi pppd[1521]: pppd 2.4.7 started by root, uid 0
Mar 2 16:49:35 raspberrypi pppd[1521]: Serial connection established.
Mar 2 16:49:35 raspberrypi pppd[1521]: Using interface ppp0
Mar 2 16:49:35 raspberrypi pppd[1521]: Connect: ppp0 <–> /dev/ttySC1
Mar 2 16:49:36 raspberrypi pppd[1521]: CHAP authentication succeeded
Mar 2 16:49:36 raspberrypi pppd[1521]: CHAP authentication succeeded
Mar 2 16:50:46 raspberrypi candy-pi-lite: [ERROR] PPP cannot be online
Mar 2 16:50:46 raspberrypi pppd[1521]: Terminating on signal 15
Mar 2 16:50:52 raspberrypi pppd[1521]: Connection terminated.
Mar 2 16:50:52 raspberrypi pppd[1521]: Serial link disconnected.
Mar 2 16:50:53 raspberrypi pppd[1521]: Modem hangup
Mar 2 16:50:53 raspberrypi pppd[1521]: Exit.
Mar 2 16:50:53 raspberrypi candy-pi-lite: [INFO] start_pppd.sh terminated: Exit Code => 16
Mar 2 16:50:54 raspberrypi candy-pi-lite: [INFO] Trying to connect…(Trial:3/3)
Mar 2 16:50:54 raspberrypi candy-pi-lite: [INFO] Starting PPP: /dev/ttySC1
Mar 2 16:50:54 raspberrypi pppd[2062]: pppd 2.4.7 started by root, uid 0
Mar 2 16:50:55 raspberrypi pppd[2062]: Serial connection established.
Mar 2 16:50:55 raspberrypi pppd[2062]: Using interface ppp0
Mar 2 16:50:55 raspberrypi pppd[2062]: Connect: ppp0 <–> /dev/ttySC1
Mar 2 16:50:56 raspberrypi pppd[2062]: CHAP authentication succeeded
Mar 2 16:50:56 raspberrypi pppd[2062]: CHAP authentication succeeded
Mar 2 16:52:05 raspberrypi candy-pi-lite: [ERROR] PPP cannot be online
Mar 2 16:52:05 raspberrypi pppd[2062]: Terminating on signal 15
Mar 2 16:52:11 raspberrypi pppd[2062]: Connection terminated.
Mar 2 16:52:12 raspberrypi pppd[2062]: Serial link disconnected.
Mar 2 16:52:13 raspberrypi pppd[2062]: Modem hangup
Mar 2 16:52:13 raspberrypi pppd[2062]: Exit.
Mar 2 16:52:13 raspberrypi candy-pi-lite: [INFO] start_pppd.sh terminated: Exit Code => 16
Mar 2 16:52:14 raspberrypi candy-pi-lite: [INFO] CANDY Pi Lite Board is initialized successfully!
Mar 2 16:52:14 raspberrypi server_main.: [NOTICE] serial_port:/dev/ttySC1 (460800 bps), nic:ppp0
Mar 2 16:52:14 raspberrypi server_main.init: [NOTICE] RESTART_SCHEDULE_CRON=>[] is ignored

以上(2/2)。


#9

詳細な情報ありがとうございます。

PPPと呼ばれる機能でオンラインになっていないことをログから確認しました。が、suspendresumeで後からオンラインにできるとのことで、SIM回線状態やアンテナ等の接続状態に関しては、疎通に必要な状態になっていると思われます。

さらに詳しく調べるため、以下の情報を教えていただけますでしょうか?

  • 使用しているRaspbian OSイメージ種類(デスクトップ版Raspbianなど)
  • Raspbianの場合はOSイメージのバージョン(cat /etc/rpi-issueを実行した結果を教えてください)
  • GPIOピンに何か接続している機器がありましたら、使用しているピンをお知らせください。
  • 使用しているUSB接続機器がありましたらお知らせください。

よろしくお願いいたします。


#10

お世話になっております。

下記、ご連絡いたします。

  • 使用しているRaspbian OSイメージ種類(デスクトップ版Raspbianなど)
    御社ご提供の OSイメージ(V5.1.0)
  • Raspbianの場合はOSイメージのバージョン( cat /etc/rpi-issue を実行した結果を教えてください)
    Raspberry Pi reference 2018-11-13
    Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 7b40fd1bc13d6496b
    b6dbd1bc02f946b7e0ac7cb, stage2-2-ja_JP
  • GPIOピンに何か接続している機器がありましたら、使用しているピンをお知らせください。
    BCM表記で

#11

申し訳ありません、記述途中で操作を誤ってしまし途中で送信してしましました。

  • 使用しているRaspbian OSイメージ種類(デスクトップ版Raspbianなど)
    御社ご提供の OSイメージ(V5.1.0)
  • Raspbianの場合はOSイメージのバージョン( cat /etc/rpi-issue を実行した結果を教えてください)
    Raspberry Pi reference 2018-11-13
    Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 7b40fd1bc13d6496b
    b6dbd1bc02f946b7e0ac7cb, stage2-2-ja_JP
  • GPIOピンに何か接続している機器がありましたら、使用しているピンをお知らせください。
    BCM表記で GPIO23 (入力設定) : 接点スイッチ, GPIO24(出力設定) : LED、
    GPIO24(出力設定) : LED、 GPIO16(出力設定) : ラズベリーパイHaertbeat設定でLED
  • 使用しているUSB接続機器がありましたらお知らせください。
    Monowireless社 Monostick(red)

以上、よろしくお願いいたします。


#12

ありがとうございます。

ソフトウェアやハードウェアの構成上の問題はなさそうに見えます。
現状では、何らかの要因でPPP接続が起動時にできないことがあり、そのままリトライをせずに終了しているため、オフラインのままとなっています。ソフトウェア側の対処を入れてモデムリセットを含めたリトライも行うように変更を行いますので、そちらでお試しいただければと思います。現在準備をしておりますのでお待ちください。


#13

お待たせいたしました。以下のtxtファイルをダウンロードしていただき、次の手順で差し替えて動作を見ていただけますでしょうか?
start_systemd.sh.txt (11.3 KB)

# 1. PCからラズパイにダウンロードしたstart_systemd.sh.txtをアップロードする
# 2. ラズパイでCANDY Pi Liteのサービスを停止する
$ sudo candy service stop
# 3. ラズパイで差し替え元のファイルの名前を変更する
$ sudo mv /opt/candy-line/candy-pi-lite/start_systemd.sh /opt/candy-line/candy-pi-lite/start_systemd.sh.org
# 4. ラズパイで新しいファイルを移動する
$ sudo start_systemd.sh.txt /opt/candy-line/candy-pi-lite/start_systemd.sh
# 5. ファイルに実行権限をつける
$ sudo chmod +x /opt/candy-line/candy-pi-lite/start_systemd.sh

電源を落としてから再起動した際に、接続が行われるか何回かお試しいただき、接続が行われるかどうかご確認いただけますか?

こちらでは、同じ状況を再現するため、以下の手順でリトライが行われることを確認しています。

  1. SORACOM Air SIM(国内)の回線を「停止中」に変更する
  2. 電源を入れて、tail -f /var/log/syslogでログの状態を確認する
  3. ログのメッセージにcandy-pi-lite: [WARN] Failed to establishing a connection. Retry after 30 seconds...が出てきたら、回線を「使用中」に変更する
  4. LEDが点滅し、ログにもcandy-pi-lite: [INFO] PPP goes onlineが出たことを確認する

お手数をおかけしますが、動作結果をお知らせいただけますでしょうか。
よろしくお願いいたします。


#14

お世話になっております。
ご連絡が遅くなり誠に申し訳ありません。

対策をいただきました当日、午前中に客先より稼働依頼があり実機はONLINEが切れない対策を行い再稼働させるため返却いたしました。
実機ではありませんが、急遽必要な部品を手配し、バックアップしてあるSDイメージにて対策内容を実施し、本日まで確認作業を行い問題が再発しないことを確認いたしました。
折を見て、実機でも対策を行いたいと考えております。

ご対応誠にありがとうございました。今後共よろしくお願いいたします。


#15

ご連絡ありがとうございました。問題が再発しないとのことで安心いたしました。
次期リリースには本変更を反映しますが、個別のファイルの入れ替えで本件への対応をされる場合は、上記手順にてお試しください。
よろしくお願いいたします。