owner のすべての投稿

M5STACK 3G拡張ボードがIPを取得するまで

経緯

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の接続完了がどうやったら、早くできるのか?が鍵のようです。

以上、ご参考までに