Strange sequences on GPRS events

[MichaG]

Hello,

Here is the context: Fastrack Supreme 20 with Firmware 7.47.4.201208311102 and Internet Library Package 5.43.1.201206250935.

I check the registration on the GMS network with +CREG with stat 1 (Home network) or 5 (Roaming).
Then I open and start a GPRS bearer and when the bearer is started, a TCP client is created with wip_TCPClientCreate.
I recently added the log of all GPRS events with adl_gprsSubscribe and I got some strange sequences.
Log are saved into flash memory and sent to a server when a new connection is available.
The time in the logs are the reception times on server side and the reception order on server side should be equal to the sending order.

[18/05/2013 04:46:24] => ADL_GPRS_EVENT_SETUP_OK
[18/05/2013 04:47:54] => ADL_GPRS_EVENT_ME_ATTACH
[18/05/2013 04:49:24] => ADL_GPRS_EVENT_ACTIVATE_OK
[18/05/2013 04:50:54] => ADL_GPRS_EVENT_ME_ATTACH

Setup, Attach and Activate are the events I’m waiting for.
But I don’t understand why there is another ATTACH event.

[18/05/2013 16:44:13] => WIP_CEV_ERROR (-988 WIP_CERR_NETWORK_UNREACHABLE)
[18/05/2013 16:45:44] => start a reconnection
[18/05/2013 16:47:13] => ADL_GPRS_EVENT_NW_CONTEXT_DEACT
[18/05/2013 16:48:44] => ADL_GPRS_EVENT_ME_CONTEXT_DEACT
[18/05/2013 16:50:13] => ADL_GPRS_EVENT_DEACTIVATE_OK
[18/05/2013 16:51:44] => ADL_GPRS_EVENT_SETUP_OK
[18/05/2013 16:53:13] => ADL_GPRS_EVENT_ACTIVATE_OK
[18/05/2013 18:38:13] => ADL_GPRS_EVENT_ME_ATTACH
[18/05/2013 18:39:44] => ADL_GPRS_EVENT_ME_ATTACH

In this sequence, there is an error on the TCP socket. So a reconnection is done (TCP socket is closed, GPRS bearer is stopped and closed, GPRS bearer is opened, started and a new TCP client is created). I will not detail but I use a state machine to call the right method at the right time. The reconnection is successful.
Here I don’t understand why the ATTACH is after the ACTIVATE_OK. From my knowledge on GPRS, the sequence order should be ATTACH then ACTIVATE.
And I don’t understand the second ATTACH event.
And I’m surprised to not have a DETACH event.

Any suggestion about these strange sequences ?

[EDIT]
In previous log, I did not log the Context ID from GPRS Event handler.
I did a test with traces, Fastrack Supreme connected to my laptop and added the Cid into bracket.
Sequence is now:

ADL;1;[GPRS]: open: → DISCONNECTED
ADL;1;[GPRS]: start: → CONNECTING
ADL;1; ----> ADL_GPRS_EVENT_SETUP_OK (1)
ADL;1;[GPRS]: GPRS CTX (cid=1) found
ADL;1;[GPRS]: GPRS EVENT SETUP OK (cid=1): GPRS activate
ADL;1; ----> ADL_GPRS_EVENT_ME_ATTACH (1)
ADL;1;[GPRS]: GPRS CTX (cid=1) found
ADL;1;[GPRS]: GPRS EVENT: 27 (cid=1)
ADL;1; ----> ADL_GPRS_EVENT_ACTIVATE_OK (1)
ADL;1;[GPRS]: GPRS CTX (cid=1) found
ADL;1;[GPRS]: GPRS EVENT ACTIVATE OK (cid=1)
ADL;1;[GPRS]: GPRS: → CONNECTED
ADL;1;[WIP] new TCPCLIENT 0x180c7734
ADL;1; ----> ADL_GPRS_EVENT_ME_ATTACH (5)
ADL;1;[WIP] CID NOT FOUND[5]

So the new question is why I got a new Cid 5 ?

Another question: how to get more details on WIP_CERR_NETWORK_UNREACHABLE error ?
On the last 3 days, I get this error at the same time around 16:44.
The modem is online from 4:30 a.m. to 10:00 p.m.

Thanks.
Marc

[awneil]

Try also logging +CGREG unsolicited notifications - I think you’ll find that ADL_GPRS_EVENT_ME_ATTACH events correspond to +CGREG: 1/5 notifications…

You might also include logging +CGEV unsolicited notifications…

[MichaG]

Thanks Awneil.

The ADL_GPRS_EVENT_ME_ATTACH event (with a Cid of 5) occurs when a +CREG and/or +CGREG notifications is received (when the cell changes).

I will also check +CGEV unsolicited notifications as you suggest.

Is there any reason to not have the GRPS DETACH Event when a WIP_CERR_NETWORK_UNREACHABLE error occurs on the TCP channel ?

Thanks.
Marc