1637846096.toit-sim-4786.hardware_id-a966ebf8-6407-4964-9685-95ac15170168.firmware-v1.5.0-rc.1.log

$ toit serial reinstall --firmware v1.5.0-rc.1 -p model.cellular.enabled=1 -p model.cellular.tx=5 -p model.cellular.rx=23 -p model.cellular.rts=19 -p model.cellular.cts=18 -p model.cellular.pwr=27 -p model.cellular.monarch=1 -p cellular.apn=nbiot.tdc.dk --port=/dev/ttyUSB0
Detecting chip type. This can take up to 10s.
Reinstalling hardware with firmware: v1.5.0-rc.1 (using model: esp32-4mb) on port /dev/ttyUSB0
Running "/home/christian/.cache/toit/tools/esptool_linux_v3.0 --chip esp32 --port /dev/ttyUSB0 --baud 921600 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0xd000 /tmp/325127044/otadata716654355 0x10000 /tmp/325127044/ota_0800936790"
esptool.py v3.0
Serial port /dev/ttyUSB0
Connecting.....
Chip is ESP32-D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: f0:08:d1:cf:a4:30
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Configuring flash size...
Auto-detected Flash size: 8MB
Compressed 8192 bytes to 31...
Writing at 0x0000d000... (100 %)
Wrote 8192 bytes (31 compressed) at 0x0000d000 in 0.0 seconds (effective 23027.4 kbit/s)...
Hash of data verified.
Compressed 1323840 bytes to 804576...
Writing at 0x00010000... (2 %)
Writing at 0x00014000... (4 %)
Writing at 0x00018000... (6 %)
Writing at 0x0001c000... (8 %)
Writing at 0x00020000... (10 %)
Writing at 0x00024000... (12 %)
Writing at 0x00028000... (14 %)
Writing at 0x0002c000... (16 %)
Writing at 0x00030000... (18 %)
Writing at 0x00034000... (20 %)
Writing at 0x00038000... (22 %)
Writing at 0x0003c000... (24 %)
Writing at 0x00040000... (26 %)
Writing at 0x00044000... (28 %)
Writing at 0x00048000... (30 %)
Writing at 0x0004c000... (32 %)
Writing at 0x00050000... (34 %)
Writing at 0x00054000... (36 %)
Writing at 0x00058000... (38 %)
Writing at 0x0005c000... (40 %)
Writing at 0x00060000... (42 %)
Writing at 0x00064000... (44 %)
Writing at 0x00068000... (46 %)
Writing at 0x0006c000... (48 %)
Writing at 0x00070000... (50 %)
Writing at 0x00074000... (52 %)
Writing at 0x00078000... (54 %)
Writing at 0x0007c000... (56 %)
Writing at 0x00080000... (58 %)
Writing at 0x00084000... (60 %)
Writing at 0x00088000... (62 %)
Writing at 0x0008c000... (64 %)
Writing at 0x00090000... (66 %)
Writing at 0x00094000... (68 %)
Writing at 0x00098000... (70 %)
Writing at 0x0009c000... (72 %)
Writing at 0x000a0000... (74 %)
Writing at 0x000a4000... (76 %)
Writing at 0x000a8000... (78 %)
Writing at 0x000ac000... (80 %)
Writing at 0x000b0000... (82 %)
Writing at 0x000b4000... (84 %)
Writing at 0x000b8000... (86 %)
Writing at 0x000bc000... (88 %)
Writing at 0x000c0000... (90 %)
Writing at 0x000c4000... (92 %)
Writing at 0x000c8000... (94 %)
Writing at 0x000cc000... (96 %)
Writing at 0x000d0000... (98 %)
Writing at 0x000d4000... (100 %)
Wrote 1323840 bytes (804576 compressed) at 0x00010000 in 13.4 seconds (effective 793.0 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
Hardware successfully reinstalled with the Toit firmware.
The hardware has been reinstalled with the following configurations:
+------------------------+----------------+
|        SETTING         |     VALUE      |
+------------------------+----------------+
| context                | remote         |
| broker.host            | device.toit.io |
| broker.cn              | device.toit.io |
| broker.port            | 9426           |
| model.cellular.pwr     | 27             |
| model.cellular.monarch | 1              |
| cellular.apn           | nbiot.tdc.dk   |
| model.cellular.rx      | 23             |
| model.cellular.rts     | 19             |
| model.cellular.cts     | 18             |
| model.cellular.enabled | 1              |
| model.cellular.tx      | 5              |
| model                  | esp32-4mb      |
+------------------------+----------------+


$ toit serial info --output table
+-------------------------------------------------------------------------+-----------+--------------------------------------+
|                                  NAME                                   |   MODEL   |             HARDWARE ID              |
+-------------------------------------------------------------------------+-----------+--------------------------------------+
| a966ebf8-6407-4964-9685-95ac15170168.743.2021-09-26.device.toitware.com | esp32-4mb | a966ebf8-6407-4964-9685-95ac15170168 |
+-------------------------------------------------------------------------+-----------+--------------------------------------+


$ toit serial monitor
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:188
ho 0 tail 12 room 4
load:0x40078000,len:12180
load:0x40080400,len:2944
entry 0x400805c8
clearing RTC memory: RTC memory is in inconsistent state
[flash reg] address 0x3f46c000, size 0x00134000
[IDENTITY] name=a966ebf8-6407-4964-9685-95ac15170168.743.2021-09-26.device.toitware.com,model=esp32-4mb
(0.015876) [toit] INFO: booting toit {sdk: v1.5.0-rc.1, model: esp32-4mb}
(0.020853) [toit.scheduler] INFO: set initial run_level {run_level: 4}
(0.495346) [toit.state] INFO: starting new session {session_id: 1, session_time: 0.502526}
[gc @ 0x3ffcf9f0* | soft limit reached (20480 >= 18432)]
[gc @ 0x3ffcf9f0* | heap: 20kb -> 8kb | external: 0kb -> 0kb | free: 9kb->9kb 1.153ms]
(0.584771) [toit.kernel] INFO: using model parameters {cellular.cts: 18, cellular.enabled: 1, cellular.monarch: 1, cellular.pwr: 27, cellular.rts: 19, cellular.rx: 23, cellular.tx: 5}
(0.697387) [toit.console_sync] INFO: loaded last console sync {time: null}
(0.709339) [toit.scheduler] INFO: running job {job: console_sync}
(0.712236) [toit.scheduler] INFO: running job {job: flush_metrics}
(0.714416) [toit.scheduler] INFO: running job {job: poll_metric_flash_usage}
[gc @ 0x3ffcf9f0* | soft limit reached (24576 >= 24576)]
[gc @ 0x3ffcf9f0* | byte array allocation failed, length = 6 (heap)]
[gc @ 0x3ffcf9f0* | heap: 24kb -> 16kb | external: 0kb -> 0kb | free: 12kb->12kb 1.774ms]
(0.719335) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(0.748191) [toit.console] INFO: waiting for console connection to be established
(0.752561) [toit.network] DEBUG: connecting {network: Cellular (nbiot.tdc.dk)}
(0.760215) [toit.metrics] INFO: persisting metrics
(0.763355) [toit.metrics] INFO: flushing metrics
[gc @ 0x3ffcf9f0* | soft limit reached (36892 >= 36864)]
[gc @ 0x3ffcf9f0* | byte array allocation failed, length = 511 (heap)]
[gc @ 0x3ffcf9f0* | heap: 36kb -> 20kb | external: 0kb -> 0kb | free: 12kb->12kb 1.978ms]
(1.108818) [toit] INFO: -> AT
(1.370196) [toit] INFO: -> AT
(1.630785) [toit] INFO: -> AT
(1.891483) [toit] INFO: -> AT
(2.152263) [toit] INFO: -> AT
[gc @ 0x3ffcf9f0* | soft limit reached (45084 >= 43050)]
[gc @ 0x3ffcf9f0* | string allocation failed, length = 6 (heap)]
[gc @ 0x3ffcf9f0* | heap: 44kb -> 28kb | external: 0kb -> 0kb | free: 6kb->6kb 2.311ms]
(2.412945) [toit] INFO: -> AT
(2.673801) [toit] INFO: -> AT
(2.844727) [toit] INFO: <- OK
(2.950573) [toit] INFO: -> ATE0
(2.958392) [toit] INFO: <- OK
(2.981516) [toit] INFO: -> AT+CMEE=2
(2.987450) [toit] INFO: <- OK
(3.010158) [toit] INFO: -> AT+CGMM
(3.015768) [toit] INFO: <- FiPy
(3.018737) [toit] INFO: <- OK
(3.040952) [toit] INFO: -> AT+CGMR
(3.061417) [toit] INFO: <- UE5.4.0.2
(3.064329) [toit] INFO: <- OK
(3.086620) [toit] INFO: -> AT+SQNCCID?
(3.092274) [toit] INFO: <- +SQNCCID: "",""
(3.094980) [toit] INFO: <- OK
(3.097535) [toit.cellular] DEBUG: initialized {model: FiPy, version: UE5.4.0.2, iccid: }
(3.117867) [toit] INFO: -> AT+CFUN=4
(3.183673) [toit] INFO: <- OK
(3.206470) [toit] INFO: -> AT+CPIN?
(3.212320) [toit] INFO: <- +CME ERROR: SIM not inserted
(3.467981) [toit] INFO: -> AT+CPIN?
(3.474003) [toit] INFO: <- +CME ERROR: SIM not inserted
(3.728571) [toit] INFO: -> AT+CPIN?
(3.831619) [toit] INFO: <- +CPIN: READY
(3.834291) [toit] INFO: <- OK
(3.856784) [toit] INFO: -> AT+CPSMS=0
(3.864250) [toit] INFO: <- OK
(3.886959) [toit] INFO: -> AT+CEDRXS=0
(3.895050) [toit] INFO: <- OK
(3.918037) [toit] INFO: -> AT+SQNIBRCFG=0
(3.938444) [toit] INFO: <- OK
(3.961357) [toit] INFO: -> AT+SQNIPSCFG=1,100
(3.978881) [toit] INFO: <- OK
(4.001848) [toit] INFO: -> AT+SQNBANDSEL=0,"standard","20"
(4.074763) [toit] INFO: <- +SQNBANDSEL: <custom>
(4.077583) [toit] INFO: <- OK
(4.100227) [toit] INFO: -> AT+SQNBANDSEL=1,"standard","20"
(4.108424) [toit] INFO: <- +CME ERROR: operation not supported
(4.130675) [toit] INFO: -> AT+CGDCONT?
(4.136648) [toit] INFO: <- +CGDCONT: 1,"IP","internet",,,,0,0,0,0,0,0,0,,0
(4.139842) [toit] INFO: <- OK
(4.162460) [toit] INFO: -> AT+CGDCONT=1,"IP","nbiot.tdc.dk"
(4.311103) [toit] INFO: <- OK
(4.333503) [toit] INFO: -> AT
(4.338055) [toit] INFO: <- OK
(4.441704) [toit] INFO: -> ATE0
(4.446760) [toit] INFO: <- OK
(4.469481) [toit] INFO: -> AT+CMEE=2
(4.516750) [toit] INFO: <- OK
(4.539248) [toit] INFO: -> AT
(4.544405) [toit] INFO: <- OK
(4.648034) [toit] INFO: -> ATE0
(4.653051) [toit] INFO: <- OK
(4.675678) [toit] INFO: -> AT+CMEE=2
(4.689832) [toit] INFO: <- OK
(4.712546) [toit] INFO: -> AT+CFUN=4
(4.718500) [toit] INFO: <- OK
(4.740990) [toit] INFO: -> AT+CPIN?
(4.746318) [toit] INFO: <- +CPIN: READY
(4.748912) [toit] INFO: <- OK
(4.771313) [toit] INFO: -> AT+CPSMS=0
(4.778242) [toit] INFO: <- OK
(4.800969) [toit] INFO: -> AT+CEDRXS=0
(4.808198) [toit] INFO: <- OK
(4.830898) [toit] INFO: -> AT+SQNIBRCFG=0
(4.842361) [toit] INFO: <- OK
(4.865159) [toit] INFO: -> AT+SQNIPSCFG=1,100
(4.881369) [toit] INFO: <- OK
(4.904211) [toit] INFO: -> AT+SQNBANDSEL=0,"standard","20"
(4.969200) [toit] INFO: <- +SQNBANDSEL: <custom>
(4.971988) [toit] INFO: <- OK
(4.994592) [toit] INFO: -> AT+SQNBANDSEL=1,"standard","20"
[gc @ 0x3ffcf9f0* | soft limit reached (57372 >= 55338)]
[gc @ 0x3ffcf9f0* | heap: 56kb -> 24kb | external: 0kb -> 0kb | free: 10kb->10kb 2.216ms]
(5.006256) [toit] INFO: <- +CME ERROR: operation not supported
(5.031483) [toit] INFO: -> AT+CGDCONT?
(5.038063) [toit] INFO: <- +CGDCONT: 1,"IP","nbiot.tdc.dk",,,,0,0,0,0,0,0,0,,0
(5.041241) [toit] INFO: <- OK
(5.063810) [toit] INFO: -> AT+CFUN=1
(5.598705) [toit] INFO: <- OK
(5.773658) [toit] INFO: <- +CEREG: 2
(5.775889) [toit] INFO: <- [URC] +CEREG [2]
(5.777934) [toit.cellular] DEBUG: attempt modem's automatic connect
(5.790683) [toit.cellular] DEBUG: connecting {operator: null, attempt: 1}
(5.797042) [toit] INFO: -> AT+COPS?
(5.804054) [toit] INFO: <- +COPS: 1
(5.806883) [toit] INFO: <- OK
(5.829471) [toit] INFO: -> AT+COPS=0,2
(5.848589) [toit] INFO: <- OK
(5.871309) [toit] INFO: -> AT+CEREG=2
(5.881616) [toit] INFO: <- OK
(5.904169) [toit] INFO: -> AT+CEREG?
(5.909721) [toit] INFO: <- +CEREG: 2,2
(5.912332) [toit] INFO: <- OK
(6.916811) [toit] INFO: -> AT
(6.922174) [toit] INFO: <- OK
(7.926752) [toit] INFO: -> AT
(7.931493) [toit] INFO: <- OK
(8.936100) [toit] INFO: -> AT
(8.942760) [toit] INFO: <- OK
(9.844368) [toit] INFO: <- +CEREG: 80
(9.846593) [toit] INFO: <- [URC] +CEREG [80]
(9.849196) [toit.cellular] DEBUG: connection failed
(9.863606) [toit] INFO: <- +CEREG: 2
(9.866022) [toit] INFO: <- *ignored* [URC] +CEREG [2]
(9.886655) [toit] INFO: -> AT+CFUN=4
(9.953622) [toit] INFO: <- OK
(9.956534) [toit] INFO: <- +CEREG: 0
(9.958518) [toit] INFO: <- *ignored* [URC] +CEREG [0]
(9.960455) [toit.cellular] DEBUG: failed, detach from network
----
Received a Toit system message but unable to send it to the Toit console for decoding.
Executing the command below will make it human readable:
----
[gc @ 0x3ffcf9f0* | soft limit reached (49761 >= 49194)]
[gc @ 0x3ffcf9f0* | string allocation failed, length = 775 (heap)]
[gc @ 0x3ffcf9f0* | heap: 48kb -> 24kb | external: 0kb -> 0kb | free: 9kb->10kb 2.307ms]
toit serial decode WyNVBVVYU1ULdjEuNS4wLXJjLjFTVQllc3AzMi00bWJbJFUjVRAAAAAAAAAAAAAAAAAAAAAAWyNVBFVFU1UJRVhDRVBUSU9OU1URQ09OTkVDVElPTiBGQUlMRURbI1UCVVNbI1UmWyNVA1VGVQBsAAI4xFsjVQNVRlUBbAACOT9bI1UDVUZVAmwAAjTBWyNVA1VGVQNsAAI07FsjVQNVRlUEbAACpvRbI1UDVUZVBUkk2FsjVQNVRlUGSSTtWyNVA1VGVQdJJMpbI1UDVUZVCGwAAqezWyNVA1VGVQlsAAKoTVsjVQNVRlUKbAACoLdbI1UDVUZVC2wAApmcWyNVA1VGVQxsAAKo/FsjVQNVRlUNbAACpY5bI1UDVUZVDkkk2FsjVQNVRlUPSSTtWyNVA1VGVRBJJHJbI1UDVUZVEWwAAqXLWyNVA1VGVRJsAAKlZ1sjVQNVRlUTbAABAUdbI1UDVUZVFGwAAZw3WyNVA1VGVRVsAAERV1sjVQNVRlUWbAABEXBbI1UDVUZVF2wAARDtWyNVA1VGVRhJJNhbI1UDVUZVGUkk7VsjVQNVRlUaSSTKWyNVA1VGVRtsAAERBlsjVQNVRlUcbAABERxbI1UDVUZVHUkx81sjVQNVRlUebAACR3BbI1UDVUZVH0kk2FsjVQNVRlUgSSTtWyNVA1VGVSFJJHJbI1UDVUZVImwAAkeFWyNVA1VGVSNsAAJHnFsjVQNVRlUkSTGIWyNVA1VGVSVJMiM=
(10.099580) [toit.network] DEBUG: error connecting {network: Cellular (nbiot.tdc.dk), error: CONNECTION FAILED}
(10.106721) [toit.network] WARN: failed to connect to any network
----
Received a Toit system message but unable to send it to the Toit console for decoding.
Executing the command below will make it human readable:
----
toit serial decode WyNVBVVYU1ULdjEuNS4wLXJjLjFTVQllc3AzMi00bWJbJFUjVRAAAAAAAAAAAAAAAAAAAAAAWyNVBFVFU1UJRVhDRVBUSU9OU1URRkFJTEVEIFRPIENPTk5FQ1RbI1UCVVNbI1UbWyNVA1VGVQBsAAKppVsjVQNVRlUBbAACqQJbI1UDVUZVAmwAAqWOWyNVA1VGVQNJJNhbI1UDVUZVBEkk7VsjVQNVRlUFSSRyWyNVA1VGVQZsAAKly1sjVQNVRlUHbAACpWdbI1UDVUZVCGwAAQFHWyNVA1VGVQlsAAGcN1sjVQNVRlUKbAABEVdbI1UDVUZVC2wAARFwWyNVA1VGVQxsAAEQ7VsjVQNVRlUNSSTYWyNVA1VGVQ5JJO1bI1UDVUZVD0kkylsjVQNVRlUQbAABEQZbI1UDVUZVEWwAAREcWyNVA1VGVRJJMfNbI1UDVUZVE2wAAkdwWyNVA1VGVRRJJNhbI1UDVUZVFUkk7VsjVQNVRlUWSSRyWyNVA1VGVRdsAAJHhVsjVQNVRlUYbAACR5xbI1UDVUZVGUkxiFsjVQNVRlUaSTIj
(10.190305) [toit] INFO: -> AT+CFUN=0
(10.196309) [toit.scheduler] INFO: changing run level {run_level: 0}
(10.200126) [toit.scheduler] INFO: going into deep sleep {ms: 4988}
(10.202148) [toit.metrics] INFO: persisting metrics
(10.446013) [toit] INFO: <- OK
(10.553955) [toit] INFO: entering deep sleep {ms: 4988}
Entering deep sleep for 4988ms
ets Jun  8 2016 00:22:57

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:188
ho 0 tail 12 room 4
load:0x40078000,len:12180
load:0x40080400,len:2944
entry 0x400805c8
[flash reg] address 0x3f46c000, size 0x00134000
[IDENTITY] name=a966ebf8-6407-4964-9685-95ac15170168.743.2021-09-26.device.toitware.com,model=esp32-4mb
(0.015872) [toit] INFO: booting toit {sdk: v1.5.0-rc.1, model: esp32-4mb}
(0.020849) [toit.scheduler] INFO: set initial run_level {run_level: 4}
(0.052667) [toit.state] INFO: resumed session {session_id: 1, session_time: 15.675328}
[gc @ 0x3ffcfa58* | soft limit reached (20480 >= 18432)]
[gc @ 0x3ffcfa58* | heap: 20kb -> 8kb | external: 0kb -> 0kb | free: 9kb->9kb 1.056ms]
(0.069755) [toit.kernel] INFO: using model parameters {cellular.cts: 18, cellular.enabled: 1, cellular.monarch: 1, cellular.pwr: 27, cellular.rts: 19, cellular.rx: 23, cellular.tx: 5}
(0.110091) [toit.console_sync] INFO: loaded last console sync {time: 10.187129}
(0.126072) [toit.scheduler] INFO: running job {job: console_sync}
[gc @ 0x3ffcfa58* | soft limit reached (24576 >= 24576)]
[gc @ 0x3ffcfa58* | heap: 24kb -> 16kb | external: 0kb -> 0kb | free: 8kb->8kb 1.743ms]
(0.129074) [toit.scheduler] INFO: running job {job: poll_metric_flash_usage}
(0.143078) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(0.152974) [toit.console] INFO: waiting for console connection to be established
(0.157172) [toit.network] DEBUG: connecting {network: Cellular (nbiot.tdc.dk)}
[gc @ 0x3ffcfa58* | soft limit reached (36892 >= 36864)]
[gc @ 0x3ffcfa58* | heap: 36kb -> 20kb | external: 0kb -> 0kb | free: 12kb->12kb 1.904ms]
(0.199812) [toit] INFO: -> AT
(0.461202) [toit] INFO: -> AT
(0.721776) [toit] INFO: -> AT
(0.982474) [toit] INFO: -> AT
(1.243314) [toit] INFO: -> AT
(1.504028) [toit] INFO: -> AT
(1.764737) [toit] INFO: -> AT
(1.933657) [toit] INFO: <- OK
(2.039649) [toit] INFO: -> ATE0
(2.047510) [toit] INFO: <- OK
(2.070240) [toit] INFO: -> AT+CMEE=2
(2.076113) [toit] INFO: <- OK
[gc @ 0x3ffcfa58* | soft limit reached (45084 >= 43050)]
[gc @ 0x3ffcfa58* | heap: 44kb -> 20kb | external: 0kb -> 0kb | free: 10kb->10kb 2.228ms]
(2.105993) [toit] INFO: -> AT+CGMM
(2.115751) [toit] INFO: <- FiPy
(2.118687) [toit] INFO: <- OK
(2.140931) [toit] INFO: -> AT+CGMR
(2.161509) [toit] INFO: <- UE5.4.0.2
(2.164433) [toit] INFO: <- OK
(2.186644) [toit] INFO: -> AT+SQNCCID?
(2.192597) [toit] INFO: <- +SQNCCID: "",""
(2.195295) [toit] INFO: <- OK
(2.197876) [toit.cellular] DEBUG: initialized {model: FiPy, version: UE5.4.0.2, iccid: }
(2.217780) [toit] INFO: -> AT+CFUN=4
(2.283151) [toit] INFO: <- OK
(2.306049) [toit] INFO: -> AT+CPIN?
(2.311947) [toit] INFO: <- +CME ERROR: SIM not inserted
(2.566836) [toit] INFO: -> AT+CPIN?
(2.572632) [toit] INFO: <- +CME ERROR: SIM not inserted
(2.827679) [toit] INFO: -> AT+CPIN?
(2.943791) [toit] INFO: <- +CPIN: READY
(2.946454) [toit] INFO: <- OK
(2.968940) [toit] INFO: -> AT+CPSMS=0
(2.976336) [toit] INFO: <- OK
(3.006408) [toit] INFO: -> AT+CEDRXS=0
(3.014093) [toit] INFO: <- OK
(3.036895) [toit] INFO: -> AT+SQNIBRCFG=0
(3.056768) [toit] INFO: <- OK
(3.079661) [toit] INFO: -> AT+SQNIPSCFG=1,100
(3.097231) [toit] INFO: <- OK
(3.120113) [toit] INFO: -> AT+SQNBANDSEL=0,"standard","20"
(3.188809) [toit] INFO: <- +SQNBANDSEL: <custom>
(3.191596) [toit] INFO: <- OK
(3.214178) [toit] INFO: -> AT+SQNBANDSEL=1,"standard","20"
(3.221129) [toit] INFO: <- +CME ERROR: operation not supported
(3.243355) [toit] INFO: -> AT+CGDCONT?
(3.250059) [toit] INFO: <- +CGDCONT: 1,"IP","nbiot.tdc.dk",,,,0,0,0,0,0,0,0,,0
(3.252911) [toit] INFO: <- OK
(3.275375) [toit] INFO: -> AT+CFUN=1
(3.346192) [toit] INFO: <- OK
(3.863105) [toit] INFO: <- +CEREG: 2
(3.865520) [toit] INFO: <- [URC] +CEREG [2]
(3.867584) [toit.cellular] DEBUG: attempt modem's automatic connect
(3.880621) [toit.cellular] DEBUG: connecting {operator: null, attempt: 2}
(3.886606) [toit] INFO: -> AT+COPS?
(3.893617) [toit] INFO: <- +COPS: 0
(3.896170) [toit] INFO: <- OK
(3.918719) [toit] INFO: -> AT+CEREG=2
(3.928565) [toit] INFO: <- OK
(3.951091) [toit] INFO: -> AT+CEREG?
(3.956486) [toit] INFO: <- +CEREG: 2,2
(3.959107) [toit] INFO: <- OK
[gc @ 0x3ffcfa58* | soft limit reached (45084 >= 43050)]
[gc @ 0x3ffcfa58* | byte array allocation failed, length = 592 (heap)]
[gc @ 0x3ffcfa58* | heap: 44kb -> 24kb | external: 0kb -> 0kb | free: 10kb->10kb 2.251ms]
(4.973018) [toit] INFO: -> AT
(4.977885) [toit] INFO: <- OK
(5.982607) [toit] INFO: -> AT
(5.987824) [toit] INFO: <- OK
(6.992835) [toit] INFO: -> AT
(7.057464) [toit] INFO: <- OK
(8.013488) [toit] INFO: <- +CEREG: 80
(8.015728) [toit] INFO: <- [URC] +CEREG [80]
(8.018316) [toit.cellular] DEBUG: connection failed
(8.036395) [toit] INFO: <- +CEREG: 2
(8.038763) [toit] INFO: <- *ignored* [URC] +CEREG [2]
(8.059365) [toit] INFO: -> AT+CFUN=4
(8.126326) [toit] INFO: <- OK
(8.129447) [toit] INFO: <- +CEREG: 0
(8.131439) [toit] INFO: <- *ignored* [URC] +CEREG [0]
(8.133373) [toit.cellular] DEBUG: failed, detach from network
----
Received a Toit system message but unable to send it to the Toit console for decoding.
Executing the command below will make it human readable:
----
toit serial decode WyNVBVVYU1ULdjEuNS4wLXJjLjFTVQllc3AzMi00bWJbJFUjVRAAAAAAAAAAAAAAAAAAAAAAWyNVBFVFU1UJRVhDRVBUSU9OU1URQ09OTkVDVElPTiBGQUlMRURbI1UCVVNbI1UmWyNVA1VGVQBsAAI4xFsjVQNVRlUBbAACOT9bI1UDVUZVAmwAAjTBWyNVA1VGVQNsAAI07FsjVQNVRlUEbAACpvRbI1UDVUZVBUkk2FsjVQNVRlUGSSTtWyNVA1VGVQdJJMpbI1UDVUZVCGwAAqezWyNVA1VGVQlsAAKoTVsjVQNVRlUKbAACoLdbI1UDVUZVC2wAApmcWyNVA1VGVQxsAAKo/FsjVQNVRlUNbAACpY5bI1UDVUZVDkkk2FsjVQNVRlUPSSTtWyNVA1VGVRBJJHJbI1UDVUZVEWwAAqXLWyNVA1VGVRJsAAKlZ1sjVQNVRlUTbAABAUdbI1UDVUZVFGwAAZw3WyNVA1VGVRVsAAERV1sjVQNVRlUWbAABEXBbI1UDVUZVF2wAARDtWyNVA1VGVRhJJNhbI1UDVUZVGUkk7VsjVQNVRlUaSSTKWyNVA1VGVRtsAAERBlsjVQNVRlUcbAABERxbI1UDVUZVHUkx81sjVQNVRlUebAACR3BbI1UDVUZVH0kk2FsjVQNVRlUgSSTtWyNVA1VGVSFJJHJbI1UDVUZVImwAAkeFWyNVA1VGVSNsAAJHnFsjVQNVRlUkSTGIWyNVA1VGVSVJMiM=
(8.242476) [toit.network] DEBUG: error connecting {network: Cellular (nbiot.tdc.dk), error: CONNECTION FAILED}
(8.249937) [toit.network] WARN: failed to connect to any network
----
Received a Toit system message but unable to send it to the Toit console for decoding.
Executing the command below will make it human readable:
----
toit serial decode WyNVBVVYU1ULdjEuNS4wLXJjLjFTVQllc3AzMi00bWJbJFUjVRAAAAAAAAAAAAAAAAAAAAAAWyNVBFVFU1UJRVhDRVBUSU9OU1URRkFJTEVEIFRPIENPTk5FQ1RbI1UCVVNbI1UbWyNVA1VGVQBsAAKppVsjVQNVRlUBbAACqQJbI1UDVUZVAmwAAqWOWyNVA1VGVQNJJNhbI1UDVUZVBEkk7VsjVQNVRlUFSSRyWyNVA1VGVQZsAAKly1sjVQNVRlUHbAACpWdbI1UDVUZVCGwAAQFHWyNVA1VGVQlsAAGcN1sjVQNVRlUKbAABEVdbI1UDVUZVC2wAARFwWyNVA1VGVQxsAAEQ7VsjVQNVRlUNSSTYWyNVA1VGVQ5JJO1bI1UDVUZVD0kkylsjVQNVRlUQbAABEQZbI1UDVUZVEWwAAREcWyNVA1VGVRJJMfNbI1UDVUZVE2wAAkdwWyNVA1VGVRRJJNhbI1UDVUZVFUkk7VsjVQNVRlUWSSRyWyNVA1VGVRdsAAJHhVsjVQNVRlUYbAACR5xbI1UDVUZVGUkxiFsjVQNVRlUaSTIj
[gc @ 0x3ffcfa58* | soft limit reached (50205 >= 49194)]
[gc @ 0x3ffcfa58* | byte array allocation failed, length = 16 (heap)]
[gc @ 0x3ffcfa58* | heap: 48kb -> 24kb | external: 1kb -> 0kb | free: 9kb->10kb 2.308ms]
(8.348799) [toit] INFO: -> AT+CFUN=0
(8.354714) [toit.scheduler] INFO: changing run level {run_level: 0}
(8.358720) [toit.scheduler] INFO: going into deep sleep {ms: 4979}
(8.360761) [toit.metrics] INFO: persisting metrics
(8.637009) [toit] INFO: <- OK
(8.744937) [toit] INFO: entering deep sleep {ms: 4979}
Entering deep sleep for 4979ms
ets Jun  8 2016 00:22:57

rst:0x5 (DEEPSLEEP_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:188
ho 0 tail 12 room 4
load:0x40078000,len:12180
load:0x40080400,len:2944
entry 0x400805c8
[flash reg] address 0x3f46c000, size 0x00134000
[IDENTITY] name=a966ebf8-6407-4964-9685-95ac15170168.743.2021-09-26.device.toitware.com,model=esp32-4mb
(0.015872) [toit] INFO: booting toit {sdk: v1.5.0-rc.1, model: esp32-4mb}
(0.020849) [toit.scheduler] INFO: set initial run_level {run_level: 4}
(0.052392) [toit.state] INFO: resumed session {session_id: 1, session_time: 29.460073}
[gc @ 0x3ffcfa58* | soft limit reached (20480 >= 18432)]
[gc @ 0x3ffcfa58* | byte array allocation failed, length = 20 (heap)]
[gc @ 0x3ffcfa58* | heap: 20kb -> 8kb | external: 0kb -> 0kb | free: 9kb->9kb 1.058ms]
(0.076253) [toit.kernel] INFO: using model parameters {cellular.cts: 18, cellular.enabled: 1, cellular.monarch: 1, cellular.pwr: 27, cellular.rts: 19, cellular.rx: 23, cellular.tx: 5}
(0.119889) [toit.console_sync] INFO: loaded last console sync {time: 23.940955}
(0.136002) [toit.scheduler] INFO: running job {job: console_sync}
[gc @ 0x3ffcfa58* | soft limit reached (24576 >= 24576)]
[gc @ 0x3ffcfa58* | heap: 24kb -> 16kb | external: 0kb -> 0kb | free: 8kb->8kb 1.730ms]
(0.146247) [toit.scheduler] INFO: running job {job: poll_metric_flash_usage}
(0.152989) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(0.162980) [toit.console] INFO: waiting for console connection to be established
(0.167093) [toit.network] DEBUG: connecting {network: Cellular (nbiot.tdc.dk)}
[gc @ 0x3ffcfa58* | soft limit reached (36892 >= 36864)]
[gc @ 0x3ffcfa58* | heap: 36kb -> 20kb | external: 0kb -> 0kb | free: 12kb->12kb 1.907ms]
(0.210541) [toit] INFO: -> AT
(0.471932) [toit] INFO: -> AT
(0.732515) [toit] INFO: -> AT
(0.993213) [toit] INFO: -> AT
(1.254233) [toit] INFO: -> AT
(1.514800) [toit] INFO: -> AT
(1.775481) [toit] INFO: -> AT
(1.953542) [toit] INFO: <- OK
(2.059541) [toit] INFO: -> ATE0
(2.067429) [toit] INFO: <- OK
(2.090051) [toit] INFO: -> AT+CMEE=2
(2.096081) [toit] INFO: <- OK
[gc @ 0x3ffcfa58* | soft limit reached (45084 >= 43050)]
[gc @ 0x3ffcfa58* | heap: 44kb -> 20kb | external: 0kb -> 0kb | free: 10kb->10kb 2.146ms]
(2.122094) [toit] INFO: -> AT+CGMM
(2.127654) [toit] INFO: <- FiPy
(2.130623) [toit] INFO: <- OK
(2.152836) [toit] INFO: -> AT+CGMR
(2.173828) [toit] INFO: <- UE5.4.0.2
(2.176513) [toit] INFO: <- OK
(2.198750) [toit] INFO: -> AT+SQNCCID?
(2.204345) [toit] INFO: <- +SQNCCID: "",""
(2.207023) [toit] INFO: <- OK
(2.209639) [toit.cellular] DEBUG: initialized {model: FiPy, version: UE5.4.0.2, iccid: }
(2.229508) [toit] INFO: -> AT+CFUN=4
(2.295243) [toit] INFO: <- OK
(2.317836) [toit] INFO: -> AT+CPIN?
(2.323562) [toit] INFO: <- +CME ERROR: SIM not inserted
(2.578451) [toit] INFO: -> AT+CPIN?
(2.584214) [toit] INFO: <- +CME ERROR: SIM not inserted
(2.838769) [toit] INFO: -> AT+CPIN?
(2.959485) [toit] INFO: <- +CPIN: READY
(2.962145) [toit] INFO: <- OK
(2.984552) [toit] INFO: -> AT+CPSMS=0
(2.991978) [toit] INFO: <- OK
(3.015276) [toit] INFO: -> AT+CEDRXS=0
(3.023272) [toit] INFO: <- OK
(3.045908) [toit] INFO: -> AT+SQNIBRCFG=0
(3.066243) [toit] INFO: <- OK
(3.089152) [toit] INFO: -> AT+SQNIPSCFG=1,100
(3.106720) [toit] INFO: <- OK
(3.129623) [toit] INFO: -> AT+SQNBANDSEL=0,"standard","20"
(3.202275) [toit] INFO: <- +SQNBANDSEL: <custom>
(3.205067) [toit] INFO: <- OK
(3.227962) [toit] INFO: -> AT+SQNBANDSEL=1,"standard","20"
(3.235842) [toit] INFO: <- +CME ERROR: operation not supported
(3.258340) [toit] INFO: -> AT+CGDCONT?
(3.265110) [toit] INFO: <- +CGDCONT: 1,"IP","nbiot.tdc.dk",,,,0,0,0,0,0,0,0,,0
(3.267964) [toit] INFO: <- OK
(3.290633) [toit] INFO: -> AT+CFUN=1
(3.361800) [toit] INFO: <- OK
(4.340076) [toit] INFO: <- +CEREG: 2
(4.342287) [toit] INFO: <- [URC] +CEREG [2]
(4.344307) [toit.cellular] DEBUG: attempt modem's automatic connect
(4.360617) [toit.cellular] DEBUG: connecting {operator: null, attempt: 3}
(4.364120) [toit] INFO: -> AT+COPS?
(4.371596) [toit] INFO: <- +COPS: 0
(4.374688) [toit] INFO: <- OK
(4.397965) [toit] INFO: -> AT+CEREG=2
(4.408221) [toit] INFO: <- OK
[gc @ 0x3ffcfa58* | soft limit reached (45084 >= 43050)]
[gc @ 0x3ffcfa58* | string allocation failed, length = 6 (heap)]
[gc @ 0x3ffcfa58* | heap: 44kb -> 24kb | external: 0kb -> 0kb | free: 10kb->10kb 2.270ms]
(4.430964) [toit] INFO: -> AT+CEREG?
(4.447486) [toit] INFO: <- +CEREG: 2,2
(4.450121) [toit] INFO: <- OK
(5.454897) [toit] INFO: -> AT
(5.460094) [toit] INFO: <- OK
(6.465255) [toit] INFO: -> AT
(6.470162) [toit] INFO: <- OK
(7.474830) [toit] INFO: -> AT
(7.479671) [toit] INFO: <- OK
(8.484320) [toit] INFO: -> AT
(8.489006) [toit] INFO: <- OK
(9.493946) [toit] INFO: -> AT
(9.498873) [toit] INFO: <- OK
(10.146590) [toit.scheduler] INFO: running job {job: persist_metrics}
(10.150026) [toit.metrics] INFO: persisting metrics
(10.223998) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(10.503588) [toit] INFO: -> AT
(10.515247) [toit] INFO: <- OK
(11.520142) [toit] INFO: -> AT
(12.147090) [toit] INFO: <- OK
(12.150086) [toit] INFO: <- +CEREG: 5,"1BBC","0059C514",7
(12.152437) [toit] INFO: <- [URC] +CEREG [5, 1BBC, 0059C514, 7]
(12.155435) [toit.cellular] DEBUG: connected successfully
(12.172542) [toit] INFO: -> AT+COPS?
(12.179672) [toit] INFO: <- +COPS: 0,2,"23801",7
(12.182432) [toit] INFO: <- OK
(12.205569) [toit.network] DEBUG: connected {network: Cellular (nbiot.tdc.dk)}
(12.224862) [toit] INFO: -> AT+CSQ
(12.232195) [toit] INFO: <- +CSQ: 14,99
(12.235387) [toit] INFO: <- OK
(12.238828) [toit.console_conn] INFO: initialized {identity: a966ebf8-6407-4964-9685-95ac15170168.743.2021-09-26.device.toitware.com}
[gc @ 0x3ffcfa58* | soft limit reached (53276 >= 49194)]
[gc @ 0x3ffcfa58* | string allocation failed, length = 16 (heap)]
[gc @ 0x3ffcfa58* | heap: 52kb -> 24kb | external: 0kb -> 0kb | free: 10kb->10kb 2.278ms]
(12.266310) [toit] INFO: -> AT+SQNDNSLKUP="device.toit.io"
(12.760963) [toit] INFO: <- +SQNDNSLKUP: <custom>
(12.764030) [toit] INFO: <- OK
(12.819290) [toit.console_conn] INFO: connecting to console {host: 35.228.86.200:9426, common_name: device.toit.io, protocol: tls}
(12.824273) [toit] INFO: -> AT+SQNSCFG=1,1,300,0,80,50
(12.836922) [toit] INFO: <- OK
(12.860604) [toit] INFO: -> AT+SQNSD=1,0,9426,"35.228.86.200",0,0,1
(13.110874) [toit] INFO: <- OK
(13.140283) [toit] INFO: -> AT+SQNSSENDEXT=1,243
(13.147108) [toit] INFO: <- >
(13.149006) [toit] INFO: -> <243 bytes>
(13.153107) [toit] INFO: <-  
(13.155332) [toit] INFO: <- OK
(13.772264) [toit] INFO: <- +SQNSRING: 1
(13.774579) [toit] INFO: <- [URC] +SQNSRING [1]
(13.795183) [toit] INFO: -> AT+SQNSI=1
(13.801852) [toit] INFO: <- +SQNSI: 1,243,847,847,0
(13.804726) [toit] INFO: <- OK
(13.827341) [toit] INFO: -> AT+SQNSRECV=1,1500
(13.833119) [toit] INFO: <- +SQNSRECV: <custom>
(13.843158) [toit] INFO: <- OK
(16.914369) [toit] INFO: -> AT+SQNSSENDEXT=1,858
(16.921213) [toit] INFO: <- >
(16.923043) [toit] INFO: -> <858 bytes>
(16.934762) [toit] INFO: <-  
(16.937309) [toit] INFO: <- OK
(16.960158) [toit] INFO: -> AT+SQNSI=1
(16.965980) [toit] INFO: <- +SQNSI: 1,1101,847,0,858
(16.969225) [toit] INFO: <- OK
(17.500308) [toit] INFO: <- +SQNSRING: 1
(17.502626) [toit] INFO: <- [URC] +SQNSRING [1]
(17.509411) [toit] INFO: <- +SQNSRING: 1
(17.511721) [toit] INFO: <- [URC] +SQNSRING [1]
(17.532497) [toit] INFO: -> AT+SQNSI=1
(17.538543) [toit] INFO: <- +SQNSI: 1,1101,1648,801,0
(17.541429) [toit] INFO: <- OK
(17.563980) [toit] INFO: -> AT+SQNSRECV=1,1500
(17.570447) [toit] INFO: <- +SQNSRECV: <custom>
(17.580026) [toit] INFO: <- OK
(17.606761) [toit.console_conn] INFO: established
(17.612501) [toit] INFO: -> AT+SQNSSENDEXT=1,31
(17.619457) [toit] INFO: <- >
(17.621299) [toit] INFO: -> <31 bytes>
(17.623074) [toit] INFO: <-  
(17.625001) [toit] INFO: <- OK
(17.628853) [toit.console] INFO: connected, starting main loop
[gc @ 0x3ffcfa58* | soft limit reached (53276 >= 49194)]
[gc @ 0x3ffcfa58* | byte array allocation failed, length = 511 (heap)]
[gc @ 0x3ffcfa58* | heap: 52kb -> 28kb | external: 0kb -> 0kb | free: 18kb->18kb 2.431ms]
(17.658774) [toit] INFO: -> AT+SQNSSENDEXT=1,52
(17.666147) [toit] INFO: <- >
(17.667808) [toit] INFO: -> <52 bytes>
(17.669558) [toit] INFO: <-  
(17.671710) [toit] INFO: <- OK
(17.694166) [toit] INFO: -> AT+SQNSI=1
(17.699838) [toit] INFO: <- +SQNSI: 1,1184,1648,0,83
(17.702914) [toit] INFO: <- OK
(17.725632) [toit] INFO: -> AT+SQNSSENDEXT=1,68
(17.731243) [toit] INFO: <- >
(17.733076) [toit] INFO: -> <68 bytes>
(17.734798) [toit] INFO: <-  
(17.736654) [toit] INFO: <- OK
(17.959746) [toit] INFO: <- +SQNSRING: 1
(17.962124) [toit] INFO: <- [URC] +SQNSRING [1]
(17.982720) [toit] INFO: -> AT+SQNSI=1
(17.988854) [toit] INFO: <- +SQNSI: 1,1252,1738,90,0
(17.991723) [toit] INFO: <- OK
(18.014331) [toit] INFO: -> AT+SQNSRECV=1,1500
(18.020014) [toit] INFO: <- +SQNSRECV: <custom>
(18.023097) [toit] INFO: <- OK
(18.033880) [toit.time] INFO: adjusting time by 454957h15m16.508293586s, accuracy: null -> 379575000 ns
(18.040300) [toit.console] INFO: received action {action: new epoch}
(18.042624) [toit.console] INFO: new epoch 58fe7654-c31d-4795-be44-1f4d182b78ff
(18.065184) [toit] INFO: -> AT+SQNSSENDEXT=1,52
(18.073496) [toit] INFO: <- >
(18.075346) [toit] INFO: -> <52 bytes>
(18.077128) [toit] INFO: <-  
(18.079059) [toit] INFO: <- OK
(18.101549) [toit] INFO: -> AT+SQNSI=1
(18.107413) [toit] INFO: <- +SQNSI: 1,1304,1738,0,52
(18.110454) [toit] INFO: <- OK
(18.133248) [toit] INFO: -> AT+SQNSSENDEXT=1,74
[gc @ 0x3ffcfa58* | soft limit reached (57372 >= 55338)]
[gc @ 0x3ffcfa58* | byte array allocation failed, length = 8 (heap)]
[gc @ 0x3ffcfa58* | heap: 56kb -> 32kb | external: 0kb -> 0kb | free: 17kb->17kb 2.693ms]
(18.148008) [toit] INFO: <- >
(18.149587) [toit] INFO: -> <74 bytes>
(18.153537) [toit] INFO: <-  
(18.156107) [toit] INFO: <- OK
(18.565917) [toit] INFO: <- +SQNSRING: 1
(18.568680) [toit] INFO: <- [URC] +SQNSRING [1]
(18.589190) [toit] INFO: -> AT+SQNSI=1
(18.595249) [toit] INFO: <- +SQNSI: 1,1378,1792,54,0
(18.598116) [toit] INFO: <- OK
(18.620664) [toit] INFO: -> AT+SQNSRECV=1,1500
(18.626742) [toit] INFO: <- +SQNSRECV: <custom>
(18.629938) [toit] INFO: <- OK
(18.652505) [toit] INFO: -> AT+SQNSSENDEXT=1,52
(18.658212) [toit] INFO: <- >
(18.660062) [toit] INFO: -> <52 bytes>
(18.661998) [toit] INFO: <-  
(18.663906) [toit] INFO: <- OK
(18.686225) [toit] INFO: -> AT+SQNSI=1
(18.692222) [toit] INFO: <- +SQNSI: 1,1430,1792,0,52
(18.695521) [toit] INFO: <- OK
(18.718203) [toit] INFO: -> AT+SQNSSENDEXT=1,58
(18.723756) [toit] INFO: <- >
(18.725468) [toit] INFO: -> <58 bytes>
(18.727204) [toit] INFO: <-  
(18.729052) [toit] INFO: <- OK
(18.988527) [toit] INFO: <- +SQNSRING: 1
(18.990754) [toit] INFO: <- [URC] +SQNSRING [1]
(19.011519) [toit] INFO: -> AT+SQNSI=1
(19.017419) [toit] INFO: <- +SQNSI: 1,1488,1864,72,0
(19.020319) [toit] INFO: <- OK
(19.044945) [toit] INFO: -> AT+SQNSRECV=1,1500
(19.051051) [toit] INFO: <- +SQNSRECV: <custom>
(19.053939) [toit] INFO: <- OK
(19.063349) [toit.console] INFO: received action {action: report config}
(19.065105) [toit.console] INFO: reporting config
(19.077009) [toit] INFO: -> AT+SQNSSENDEXT=1,52
(19.082627) [toit] INFO: <- >
(19.084067) [toit] INFO: -> <52 bytes>
(19.085900) [toit] INFO: <-  
(19.088171) [toit] INFO: <- OK
(19.110500) [toit] INFO: -> AT+SQNSI=1
(19.116327) [toit] INFO: <- +SQNSI: 1,1540,1864,0,52
(19.119364) [toit] INFO: <- OK
(19.142024) [toit] INFO: -> AT+SQNSSENDEXT=1,235
(19.147416) [toit] INFO: <- >
(19.148991) [toit] INFO: -> <235 bytes>
(19.152217) [toit] INFO: <-  
(19.154386) [toit] INFO: <- OK
(19.455652) [toit] INFO: <- +SQNSRING: 1
(19.457847) [toit] INFO: <- [URC] +SQNSRING [1]
(19.478481) [toit] INFO: -> AT+SQNSI=1
(19.484413) [toit] INFO: <- +SQNSI: 1,1775,1918,54,0
(19.487287) [toit] INFO: <- OK
(19.509825) [toit] INFO: -> AT+SQNSRECV=1,1500
(19.515626) [toit] INFO: <- +SQNSRECV: <custom>
(19.518607) [toit] INFO: <- OK
(19.545386) [toit] INFO: -> AT+SQNSSENDEXT=1,52
(19.551035) [toit] INFO: <- >
(19.552474) [toit] INFO: -> <52 bytes>
(19.554487) [toit] INFO: <-  
(19.556517) [toit] INFO: <- OK
(19.578924) [toit] INFO: -> AT+SQNSI=1
(19.584759) [toit] INFO: <- +SQNSI: 1,1827,1918,0,52
(19.587833) [toit] INFO: <- OK
(19.610465) [toit] INFO: -> AT+SQNSSENDEXT=1,58
(19.615663) [toit] INFO: <- >
(19.617257) [toit] INFO: -> <58 bytes>
(19.618928) [toit] INFO: <-  
(19.620763) [toit] INFO: <- OK
(20.187210) [toit.scheduler] INFO: running job {job: persist_metrics}
[gc @ 0x3ffcfa58* | soft limit reached (65564 >= 61482)]
[gc @ 0x3ffcfa58* | heap: 64kb -> 32kb | external: 0kb -> 0kb | free: 17kb->17kb 2.661ms]
(20.198867) [toit] INFO: -> AT+CSQ
(20.204882) [toit] INFO: <- +CSQ: 13,99
(20.207654) [toit] INFO: <- OK
(20.210599) [toit.metrics] INFO: persisting metrics
(20.266041) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(20.576250) [toit] INFO: <- +SQNSRING: 1
(20.579077) [toit] INFO: <- [URC] +SQNSRING [1]
(20.599849) [toit] INFO: -> AT+SQNSI=1
(20.605970) [toit] INFO: <- +SQNSI: 1,1885,2191,273,0
(20.608902) [toit] INFO: <- OK
(20.631441) [toit] INFO: -> AT+SQNSRECV=1,1500
(20.637566) [toit] INFO: <- +SQNSRECV: <custom>
(20.640741) [toit] INFO: <- OK
(20.654954) [toit.console] INFO: received action {action: config update}
(20.673918) [toit.kernel] INFO: using model parameters {cellular.cts: 18, cellular.enabled: 1, cellular.monarch: 1, cellular.pwr: 27, cellular.rts: 19, cellular.rx: 23, cellular.tx: 5}
(20.682763) [toit.console] INFO: config updated: 2670764
(20.694020) [toit] INFO: -> AT+SQNSSENDEXT=1,52
(20.700980) [toit] INFO: <- >
(20.702567) [toit] INFO: -> <52 bytes>
(20.704317) [toit] INFO: <-  
(20.706256) [toit] INFO: <- OK
(20.730144) [toit] INFO: -> AT+SQNSI=1
(20.736573) [toit] INFO: <- +SQNSI: 1,1937,2191,0,52
(20.739683) [toit] INFO: <- OK
(20.762487) [toit] INFO: -> AT+SQNSSENDEXT=1,60
(20.767726) [toit] INFO: <- >
(20.769305) [toit] INFO: -> <60 bytes>
(20.771189) [toit] INFO: <-  
(20.773077) [toit] INFO: <- OK
[gc @ 0x3ffcfa58* | soft limit reached (61698 >= 61482)]
[gc @ 0x3ffcfa58* | string allocation failed, length = 6 (heap)]
[gc @ 0x3ffcfa58* | heap: 60kb -> 32kb | external: 0kb -> 0kb | free: 17kb->17kb 2.744ms]
(21.079752) [toit] INFO: <- +SQNSRING: 1
(21.093279) [toit] INFO: <- [URC] +SQNSRING [1]
(21.113812) [toit] INFO: -> AT+SQNSI=1
(21.119764) [toit] INFO: <- +SQNSI: 1,1997,2263,72,0
(21.122629) [toit] INFO: <- OK
(21.145256) [toit] INFO: -> AT+SQNSRECV=1,1500
(21.151224) [toit] INFO: <- +SQNSRECV: <custom>
(21.154118) [toit] INFO: <- OK
(21.163697) [toit.console] INFO: synchronized with console
(21.194013) [toit] INFO: -> AT+SQNSI=1
(21.201643) [toit] INFO: <- +SQNSI: 1,1997,2263,0,0
(21.204596) [toit] INFO: <- OK
(21.227081) [toit] INFO: -> AT+SQNSSENDEXT=1,55
(21.232698) [toit] INFO: <- >
(21.234265) [toit] INFO: -> <55 bytes>
(21.236133) [toit] INFO: <-  
(21.238049) [toit] INFO: <- OK
(21.260500) [toit] INFO: -> AT+SQNSSENDEXT=1,1209
(21.266240) [toit] INFO: <- >
(21.267898) [toit] INFO: -> <1209 bytes>
(21.284545) [toit] INFO: <-  
(21.286738) [toit] INFO: <- OK
(21.309617) [toit] INFO: -> AT+SQNSSENDEXT=1,56
(21.315556) [toit] INFO: <- >
(21.317424) [toit] INFO: -> <56 bytes>
(21.319143) [toit] INFO: <-  
(21.320990) [toit] INFO: <- OK
(21.343469) [toit] INFO: -> AT+SQNSSENDEXT=1,1224
[gc @ 0x3ffcfa58* | soft limit reached (65564 >= 61482)]
[gc @ 0x3ffcfa58* | string allocation failed, length = 6 (heap)]
[gc @ 0x3ffcfa58* | heap: 64kb -> 36kb | external: 0kb -> 0kb | free: 17kb->17kb 3.010ms]
(21.348872) [toit] INFO: <- >
(21.362590) [toit] INFO: -> <1224 bytes>
(21.367315) [toit] INFO: <-  
(21.369481) [toit] INFO: <- OK
(21.392618) [toit] INFO: -> AT+SQNSSENDEXT=1,55
(21.398425) [toit] INFO: <- >
(21.400356) [toit] INFO: -> <55 bytes>
(21.402086) [toit] INFO: <-  
(21.403954) [toit] INFO: <- OK
(21.981896) [toit] INFO: <- +SQNSRING: 1
(21.984195) [toit] INFO: <- [URC] +SQNSRING [1]
(22.004813) [toit] INFO: -> AT+SQNSI=1
(22.010792) [toit] INFO: <- +SQNSI: 1,4596,2306,43,0
(22.013637) [toit] INFO: <- OK
(22.036435) [toit] INFO: -> AT+SQNSRECV=1,1500
(22.042017) [toit] INFO: <- +SQNSRECV: <custom>
(22.044912) [toit] INFO: <- OK
(22.068147) [toit] INFO: -> AT+SQNSI=1
(22.075786) [toit] INFO: <- +SQNSI: 1,4596,2306,0,0
(22.078751) [toit] INFO: <- OK
(22.286253) [toit] INFO: <- +SQNSRING: 1
(22.288523) [toit] INFO: <- [URC] +SQNSRING [1]
(22.290880) [toit] INFO: <- +SQNSRING: 1
(22.292885) [toit] INFO: <- [URC] +SQNSRING [1]
(22.313877) [toit] INFO: -> AT+SQNSI=1
(22.319652) [toit] INFO: <- +SQNSI: 1,4596,2388,82,0
(22.322529) [toit] INFO: <- OK
(22.345109) [toit] INFO: -> AT+SQNSRECV=1,1500
(22.351097) [toit] INFO: <- +SQNSRECV: <custom>
(22.354003) [toit] INFO: <- OK
(22.385025) [toit] INFO: -> AT+SQNSI=1
(22.392799) [toit] INFO: <- +SQNSI: 1,4596,2388,0,0
(22.395751) [toit] INFO: <- OK
(22.418239) [toit] INFO: -> AT+SQNSSENDEXT=1,55
(22.424011) [toit] INFO: <- >
(22.425578) [toit] INFO: -> <55 bytes>
(22.427450) [toit] INFO: <-  
(22.429362) [toit] INFO: <- OK
(22.451918) [toit] INFO: -> AT+SQNSSENDEXT=1,36
(22.462140) [toit] INFO: <- >
(22.463939) [toit] INFO: -> <36 bytes>
(22.465713) [toit] INFO: <-  
(22.467608) [toit] INFO: <- OK
(22.490081) [toit] INFO: -> AT+SQNSSENDEXT=1,56
(22.495523) [toit] INFO: <- >
(22.497728) [toit] INFO: -> <56 bytes>
(22.499518) [toit] INFO: <-  
(22.501401) [toit] INFO: <- OK
(23.400472) [toit] INFO: -> AT
(23.405054) [toit] INFO: <- OK
(24.409538) [toit] INFO: -> AT
(24.414321) [toit] INFO: <- OK
(25.418646) [toit] INFO: -> AT
(25.423351) [toit] INFO: <- OK
(26.428386) [toit] INFO: -> AT
[gc @ 0x3ffcfa58* | soft limit reached (69660 >= 67626)]
[gc @ 0x3ffcfa58* | heap: 68kb -> 28kb | external: 0kb -> 0kb | free: 17kb->17kb 2.695ms]
(26.437826) [toit] INFO: <- OK
(27.442700) [toit] INFO: -> AT
(27.447673) [toit] INFO: <- OK
(28.452340) [toit] INFO: -> AT
(28.456630) [toit] INFO: <- OK
(29.461247) [toit] INFO: -> AT
(29.465714) [toit] INFO: <- OK
(29.932747) [toit] INFO: <- +CEREG: 80
(29.935162) [toit] INFO: <- *ignored* [URC] +CEREG [80]
(30.265045) [toit.scheduler] INFO: running job {job: persist_metrics}
(30.269993) [toit] INFO: -> AT+CSQ
(30.277065) [toit] INFO: <- +CSQ: 99,99
(30.279880) [toit] INFO: <- OK
(30.282360) [toit.metrics] INFO: persisting metrics
(30.309850) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(30.470728) [toit] INFO: -> AT
(30.475900) [toit] INFO: <- OK
(30.607582) [toit] INFO: <- +CEREG: 5,"1BBC","00EEAE14",7
(30.610070) [toit] INFO: <- *ignored* [URC] +CEREG [5, 1BBC, 00EEAE14, 7]
(31.480764) [toit] INFO: -> AT
(31.485391) [toit] INFO: <- OK
(32.489864) [toit] INFO: -> AT
(32.494478) [toit] INFO: <- OK
(33.499220) [toit] INFO: -> AT
(33.503670) [toit] INFO: <- OK
(34.508450) [toit] INFO: -> AT
(34.512949) [toit] INFO: <- OK
[gc @ 0x3ffcfa58* | soft limit reached (57372 >= 55338)]
[gc @ 0x3ffcfa58* | string allocation failed, length = 0 (heap)]
[gc @ 0x3ffcfa58* | heap: 56kb -> 32kb | external: 0kb -> 0kb | free: 17kb->17kb 2.652ms]
(35.525851) [toit] INFO: -> AT
(35.531215) [toit] INFO: <- OK
(36.535948) [toit] INFO: -> AT
(36.540642) [toit] INFO: <- OK
(37.271305) [toit] INFO: <- +CEREG: 80
(37.273804) [toit] INFO: <- *ignored* [URC] +CEREG [80]
(37.545158) [toit] INFO: -> AT
(37.550026) [toit] INFO: <- OK
(38.554348) [toit] INFO: -> AT
(38.558963) [toit] INFO: <- OK
(39.563366) [toit] INFO: -> AT
(39.567804) [toit] INFO: <- OK
(40.324209) [toit.scheduler] INFO: running job {job: persist_metrics}
(40.328969) [toit] INFO: -> AT+CSQ
(40.334880) [toit] INFO: <- +CSQ: 99,99
(40.337621) [toit] INFO: <- OK
(40.340114) [toit.metrics] INFO: persisting metrics
(40.355536) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(40.572536) [toit] INFO: -> AT
(40.577669) [toit] INFO: <- OK
(41.582270) [toit] INFO: -> AT
(41.586994) [toit] INFO: <- OK
(42.591393) [toit] INFO: -> AT
(42.595982) [toit] INFO: <- OK
(42.844341) [toit] INFO: <- +CEREG: 0
(42.846776) [toit] INFO: <- *ignored* [URC] +CEREG [0]
(43.600646) [toit] INFO: -> AT
(43.605286) [toit] INFO: <- OK
(44.609581) [toit] INFO: -> AT
(44.613948) [toit] INFO: <- OK
(45.618533) [toit] INFO: -> AT
(45.623207) [toit] INFO: <- OK
(46.628447) [toit] INFO: -> AT
(46.632855) [toit] INFO: <- OK
(47.637227) [toit] INFO: -> AT
(47.641671) [toit] INFO: <- OK
(48.646044) [toit] INFO: -> AT
(48.650841) [toit] INFO: <- OK
(49.655389) [toit] INFO: -> AT
(49.660445) [toit] INFO: <- OK
(50.382761) [toit.scheduler] INFO: running job {job: persist_metrics}
[gc @ 0x3ffcfa58* | soft limit reached (65564 >= 61482)]
[gc @ 0x3ffcfa58* | heap: 64kb -> 32kb | external: 0kb -> 0kb | free: 17kb->17kb 2.711ms]
(50.394403) [toit] INFO: -> AT+CSQ
(50.400365) [toit] INFO: <- +CSQ: 19,99
(50.403196) [toit] INFO: <- OK
(50.405954) [toit.metrics] INFO: persisting metrics
(50.425540) [toit.scheduler] INFO: running job {job: poll_metric_memory_profile}
(50.666076) [toit] INFO: -> AT
(50.671370) [toit] INFO: <- OK
(51.676040) [toit] INFO: -> AT
(51.680522) [toit] INFO: <- OK
(52.684926) [toit] INFO: -> AT
(52.689556) [toit] INFO: <- OK
(53.694309) [toit] INFO: -> AT
(53.698833) [toit] INFO: <- OK
(54.703355) [toit] INFO: -> AT
(54.708780) [toit] INFO: <- OK
(55.713539) [toit] INFO: -> AT
(55.718580) [toit] INFO: <- OK
(56.723348) [toit] INFO: -> AT
(56.727664) [toit] INFO: <- OK