経緯
M5STACK用の拡張3Gボードを評価しているところなのですが、通信が可能になるIPアドレス取得できるまでの時間が長いので、何に時間かかっているのか?を調べてみた。
IPアドレス取得までの時間を計測するコード
01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 | #include <M5Stack.h> #define CONSOLE Serial #define MODEM Serial2 #define TINY_GSM_DEBUG Serial #define TINY_GSM_MODEM_UBLOX #include <TinyGsmClient.h> TinyGsm modem(Serial2); TinyGsmClient ctx(modem); void setup() { char buf[64]; int nRet; M5.begin(); M5.Lcd.clear(BLACK); M5.Lcd.setTextColor(WHITE); M5.Lcd.println(F("M5Stack + 3G Module")); MODEM.begin(115200, SERIAL_8N1, 16, 17); // 3G MODULE uint64_t t1 = millis(); CONSOLE.println(F("modem.restart()")); M5.Lcd.print(F("modem.restart()")); modem.restart(); M5.Lcd.println(F("done")); CONSOLE.println(F("getModemInfo:")); M5.Lcd.print(F("getModemInfo:")); String modemInfo = modem.getModemInfo(); M5.Lcd.println(modemInfo); CONSOLE.println(F("waitForNetwork()")); M5.Lcd.print(F("waitForNetwork()")); while (!modem.waitForNetwork()) M5.Lcd.print("."); M5.Lcd.println(F("Ok")); CONSOLE.println(F("gprsConnect(soracom.io)")); M5.Lcd.print(F("gprsConnect(soracom.io)")); modem.gprsConnect("soracom.io", "sora", "sora"); // modem.gprsConnect("mineo-d.jp", "mineo@k-opti.com", "mineo"); M5.Lcd.println(F("done")); CONSOLE.println(F("isNetworkConnected()")); M5.Lcd.print(F("isNetworkConnected()")); while (!modem.isNetworkConnected()) M5.Lcd.print("."); M5.Lcd.println(F("Ok")); M5.Lcd.print(F("My IP addr: ")); IPAddress ipaddr = modem.localIP(); M5.Lcd.print(ipaddr); CONSOLE.println(ipaddr); CONSOLE.printf("Time = %d [ms]\r\n",millis() - t1); } void loop() { if (MODEM.available() > 0) { CONSOLE.write(MODEM.read()); } if (CONSOLE.available()) { MODEM.write(CONSOLE.read()); } } |
3つのSIMで計測してみた(Docomo網)
SORACOM IoT SIM(Plan01s)
1回目 51433ms、2回目 51984ms、3回目 67185ms
SORACOM IoT SIM(Plan-D)
1回目 51802ms、2回目 65727ms、3回目 50859ms
mineo Docomoプラン(APN変更しての測定)
1回目 52164ms、2回目 68773ms、3回目 53348ms
結果としては、SIMに関係なく、大体1分近く時間がかかることが判明
どんなATコマンドをやりとりしているのか?
TinyGSMCommon.h内のsendAT関数内のコメントアウトされていたATコマンドを表示するように設定した状況で、取得したログ
01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 | 13:13:14.696 -> modem.restart() 13:13:14.696 -> [765] ### AT: 13:13:15.009 -> [1064] ### AT: 13:13:15.302 -> [1363] ### AT: 13:13:15.589 -> [1662] ### AT: 13:13:15.912 -> [1961] ### AT: 13:13:16.196 -> [2260] ### AT: 13:13:16.508 -> [2559] ### AT: 13:13:16.800 -> [2858] ### AT: 13:13:17.089 -> [3157] ### AT: 13:13:17.382 -> [3456] ### AT: 13:13:17.702 -> [3755] ### AT: 13:13:17.702 -> [3758] ### AT: +CFUN=16 13:13:21.200 -> [7246] ### TinyGSM Version: 0.7.9 13:13:21.200 -> [7246] ### AT: 13:13:21.491 -> [7545] ### AT: 13:13:21.784 -> [7844] ### AT: 13:13:22.072 -> [8143] ### AT: 13:13:22.395 -> [8442] ### AT: 13:13:22.685 -> [8741] ### AT: 13:13:22.962 -> [9040] ### AT: 13:13:23.273 -> [9339] ### AT: 13:13:23.273 -> [9342] ### AT: E0 13:13:23.273 -> [9347] ### AT: +CMEE=2 13:13:23.273 -> [9351] ### AT: +CGMI 13:13:23.307 -> [9355] ### AT: +GMM 13:13:23.307 -> [9359] ### Modem: u-blox SARA-U201 13:13:23.307 -> [9360] ### AT: +CPIN? 13:13:24.308 -> [10367] ### AT: +CPIN? 13:13:24.308 -> getModemInfo: 13:13:24.308 -> [10374] ### AT: I 13:13:24.346 -> waitForNetwork() 13:13:24.346 -> [10393] ### AT: +CGREG? 13:13:24.596 -> [10649] ### AT: +CGREG? 13:13:24.852 -> [10904] ### AT: +CGREG? 13:13:25.102 -> [11160] ### AT: +CGREG? 13:13:25.351 -> [11416] ### AT: +CGREG? 13:13:25.607 -> [11672] ### AT: +CGREG? 13:13:25.856 -> [11928] ### AT: +CGREG? 13:13:26.109 -> [12183] ### AT: +CGREG? 13:13:26.362 -> [12438] ### AT: +CGREG? 13:13:26.619 -> [12693] ### AT: +CGREG? 13:13:26.902 -> [12948] ### AT: +CGREG? 13:13:27.151 -> [13203] ### AT: +CGREG? 13:13:27.403 -> [13458] ### AT: +CGREG? 13:13:27.650 -> [13714] ### AT: +CGREG? 13:13:27.903 -> [13969] ### AT: +CGREG? 13:13:28.150 -> [14224] ### AT: +CGREG? 13:13:28.436 -> [14479] ### AT: +CGREG? 13:13:28.687 -> [14735] ### AT: +CGREG? 13:13:28.938 -> [14991] ### AT: +CGREG? 13:13:29.191 -> [15246] ### AT: +CGREG? 13:13:29.437 -> [15502] ### AT: +CGREG? 13:13:29.688 -> [15758] ### AT: +CGREG? 13:13:29.946 -> [16013] ### AT: +CGREG? 13:13:30.196 -> [16268] ### AT: +CGREG? 13:13:30.447 -> [16524] ### AT: +CGREG? 13:13:30.726 -> [16779] ### AT: +CGREG? 13:13:30.981 -> [17035] ### AT: +CGREG? 13:13:31.232 -> [17290] ### AT: +CGREG? 13:13:31.487 -> [17545] ### AT: +CGREG? 13:13:31.736 -> [17800] ### AT: +CGREG? 13:13:31.986 -> [18056] ### AT: +CGREG? 13:13:32.240 -> [18312] ### AT: +CGREG? 13:13:32.491 -> [18567] ### AT: +CGREG? 13:13:32.746 -> [18822] ### AT: +CGREG? 13:13:33.031 -> [19077] ### AT: +CGREG? 13:13:33.031 -> gprsConnect(soracom.io) 13:13:33.031 -> [19084] ### AT: +UPSDA=0,4 13:13:33.031 -> [19092] ### AT: +CGATT=1 13:13:33.031 -> [19097] ### AT: +UPSD=0,1," soracom.io " 13:13:33.031 -> [19103] ### AT: +UPSD=0,2," sora " 13:13:33.031 -> [19108] ### AT: +UPSD=0,3," sora " 13:13:33.068 -> [19116] ### AT: +UPSD=0,7,"0.0.0.0" 13:13:33.068 -> [19121] ### AT: +UPSDA=0,3 13:14:06.034 -> [52112] ### AT: +UPSND=0,8 13:14:06.071 -> isNetworkConnected() 13:14:06.071 -> [52120] ### AT: +CGREG? 13:14:06.071 -> [52127] ### AT: +UPSND=0,0 13:14:06.071 -> 10.234.40.104 13:14:06.071 -> Time = 51370 [ms] |
解説
modem.restart()関数内では、モデムの応答を確認した後、初期化コマンド(AT+CFUN=16)を送った後に、エコーOFFとかやった後に、SIMの状態を確認するというないようで、モデムが応答するまで、3〜4秒もかかっているのが気になりますが、MODEMが起動するのに、それだけかかるということなのでしょう。
waitForNetwork()関数は、3Gの網を探して、接続するということで、見つかるまでに9秒ぐらいかかっているようです。
gprsConnect()関数は、PDPに接続する為、APNの情報や認証情報を送った後に、PDPに接続するまで、33秒程度かかっているようです。(ここが遅い原因!?)
isNetworkConnected()は、PDPに接続できているのか?を確認する関数で、これは、あってもなくてもいいかな?と思います。
とりあえず、9秒かかっているwaitForNetwork()関数を抜いてみるとどうなるのか?
01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 | 13:35:57.697 -> modem.restart() 13:35:57.697 -> [765] ### AT: 13:35:57.980 -> [1064] ### AT: 13:35:58.264 -> [1363] ### AT: 13:35:58.577 -> [1662] ### AT: 13:35:58.890 -> [1961] ### AT: 13:35:59.181 -> [2260] ### AT: 13:35:59.464 -> [2559] ### AT: 13:35:59.791 -> [2858] ### AT: 13:36:00.074 -> [3157] ### AT: 13:36:00.374 -> [3456] ### AT: 13:36:00.662 -> [3755] ### AT: 13:36:00.662 -> [3758] ### AT: +CFUN=16 13:36:04.158 -> [7245] ### TinyGSM Version: 0.7.9 13:36:04.158 -> [7245] ### AT: 13:36:04.452 -> [7544] ### AT: 13:36:04.741 -> [7843] ### AT: 13:36:05.060 -> [8142] ### AT: 13:36:05.349 -> [8441] ### AT: 13:36:05.673 -> [8740] ### AT: 13:36:05.966 -> [9039] ### AT: 13:36:06.247 -> [9338] ### AT: 13:36:06.247 -> [9341] ### AT: E0 13:36:06.247 -> [9345] ### AT: +CMEE=2 13:36:06.286 -> [9349] ### AT: +CGMI 13:36:06.286 -> [9353] ### AT: +GMM 13:36:06.286 -> [9358] ### Modem: u-blox SARA-U201 13:36:06.286 -> [9359] ### AT: +CPIN? 13:36:07.265 -> [10365] ### AT: +CPIN? 13:36:07.301 -> getModemInfo: 13:36:07.301 -> [10372] ### AT: I 13:36:07.301 -> gprsConnect(soracom.io) 13:36:07.301 -> [10392] ### AT: +UPSDA=0,4 13:36:07.301 -> [10400] ### AT: +CGATT=1 13:36:15.988 -> [19076] ### AT: +UPSD=0,1," soracom.io " 13:36:15.988 -> [19081] ### AT: +UPSD=0,2," sora " 13:36:15.988 -> [19087] ### AT: +UPSD=0,3," sora " 13:36:16.026 -> [19093] ### AT: +UPSD=0,7,"0.0.0.0" 13:36:16.026 -> [19098] ### AT: +UPSDA=0,3 13:36:49.863 -> [52949] ### AT: +UPSND=0,8 13:36:49.863 -> isNetworkConnected() 13:36:49.863 -> [52956] ### AT: +CGREG? 13:36:49.863 -> [52963] ### AT: +UPSND=0,0 13:36:49.901 -> 10.234.40.104 13:36:49.901 -> Time = 52205 [ms] |
考察
waitForNetwork()を抜いてみても、トータルの時間は変わらずってことで、今度は何処に時間がかかっているのか?を見てみると、gprsConnect()関数で、AT+CGATT=1の応答が、長くなっているのがわかります。AT+CGATT=1で、3Gの網に接続を確認しているので、内部的には、waitForNetwork()と同様のことをやっているので、トータル時間は変わらないですね。PDPの接続完了がどうやったら、早くできるのか?が鍵のようです。
以上、ご参考までに