5:34 p.m.
I'm integrating a new Cinterion module and have a small issue I haven't been able
to solve nicely in Ofono. One of their commands responds with a list of stuff, followed by
an OK but also after the OK there is an empty line. Which is of course wrong, but it might
not be solved for a while. Using the g_at_chat_send function with a callback doesn't
seem to work then, the callback will not be called it seems and I get stuck in the
sequence. Can I without modifying the AT parser handle this somehow?
/Mattias
11:20 p.m.
Hi Mattias,
On 06/20/2018 02:34 AM, Mattias Månsson wrote:
I'm integrating a new Cinterion module and have a small issue I
haven't
been able to solve nicely in Ofono. One of their commands responds with
a list of stuff, followed by an OK but also after the OK there is an
empty line. Which is of course wrong, but it might not be solved for a
while. Using the g_at_chat_send function with a callback doesn't seem to
work then, the callback will not be called it seems and I get stuck in
the sequence. Can I without modifying the AT parser handle this somehow?
Nope, the parser is what actually drives command recognition. So
sending empty commands, etc won't work.
If you're using the gsmv1 parser, then try switching to permissive.
Permissive is generally able to deal with such situations.
Regards,
-Denis
11:24 p.m.
New subject: SV: Handling empty row from AT command
It seems we already use that parser though:
syntax = g_at_syntax_new_gsm_permissive();
chat = g_at_chat_new(channel, syntax);
________________________________
Från: Denis Kenzior <denkenz(a)gmail.com>
Skickat: den 20 juni 2018 15:20:13
Till: Mattias Månsson; ofono(a)ofono.org
Ämne: Re: Handling empty row from AT command
Hi Mattias,
On 06/20/2018 02:34 AM, Mattias Månsson wrote:
I'm integrating a new Cinterion module and have a small issue I
haven't
been able to solve nicely in Ofono. One of their commands responds with
a list of stuff, followed by an OK but also after the OK there is an
empty line. Which is of course wrong, but it might not be solved for a
while. Using the g_at_chat_send function with a callback doesn't seem to
work then, the callback will not be called it seems and I get stuck in
the sequence. Can I without modifying the AT parser handle this somehow?
Nope, the parser is what actually drives command recognition. So
sending empty commands, etc won't work.
If you're using the gsmv1 parser, then try switching to permissive.
Permissive is generally able to deal with such situations.
Regards,
-Denis
11:30 p.m.
New subject: SV: Handling empty row from AT command
Hi Mattias,
On 06/20/2018 08:24 AM, Mattias Månsson wrote:
It seems we already use that parser though:
syntax = g_at_syntax_new_gsm_permissive();
chat = g_at_chat_new(channel, syntax);
Not sure then. Permissive should be taking care of the issue you
describe, e.g it skips any empty lines:
case GSM_PERMISSIVE_STATE_IDLE:
if (byte == '\r' || byte == '\n')
/* ignore */;
Maybe there's something more subtle going on? Are there stray
whitespace characters or something else in the spurious response? You
would have to trace why the permissive syntax fails and either fix it or
design your own.
Regards,
-Denis
11:33 p.m.
New subject: SV: SV: Handling empty row from AT command
I will do some experiments and come back to you with logs...
________________________________
Från: Denis Kenzior <denkenz(a)gmail.com>
Skickat: den 20 juni 2018 15:30:00
Till: Mattias Månsson; ofono(a)ofono.org
Ämne: Re: SV: Handling empty row from AT command
Hi Mattias,
On 06/20/2018 08:24 AM, Mattias Månsson wrote:
It seems we already use that parser though:
syntax = g_at_syntax_new_gsm_permissive();
chat = g_at_chat_new(channel, syntax);
Not sure then. Permissive should be taking care of the issue you
describe, e.g it skips any empty lines:
case GSM_PERMISSIVE_STATE_IDLE:
if (byte == '\r' || byte == '\n')
/* ignore */;
Maybe there's something more subtle going on? Are there stray
whitespace characters or something else in the spurious response? You
would have to trace why the permissive syntax fails and either fix it or
design your own.
Regards,
-Denis
11:58 p.m.
New subject: SV: SV: Handling empty row from AT command
OK, I think the problem is not exactly as I described it. It is probably caused by the
empty line, but the result is that the next AT command never completes.
My sequence is started as this:
g_at_chat_send(data->app, "AT+XSYSTRACE=30", none_prefix, trace_start_at_cb,
data, NULL);
then in trace_start_at_cb increase a counter and send a new command each time the callback
is called. In total I send this sequence:
g_at_chat_send(data->app, "AT+XSYSTRACE=30", none_prefix, trace_start_at_cb,
data, NULL);
g_at_chat_send(data->app, "AT+XSYSTRACE=40", none_prefix, trace_start_at_cb,
data, NULL);
g_at_chat_send(data->app, "AT+XSYSTRACE=50", none_prefix, trace_start_at_cb,
data, NULL);
g_at_chat_send(data->app, "AT+XSYSTRACE=0,<huge mask>", none_prefix,
trace_start_at_cb, data, NULL);
The problem is that if I run this sequence, I never get passed the AT+XSYSTRACE=50 as seen
here:
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: AppFinally woke up the modem
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=30\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=40\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nDecoder List 0 bytes
sent\r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=50\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\n\r\n
But if I skip the AT+XSYSTRACE=40, the sequence runs fine:
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: AppFinally woke up the modem
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT+XSYSTRACE=30\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT+XSYSTRACE=50\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: plugins/verimalto.c:trace_start_at_cb() Trace
cmd:
AT+XSYSTRACE=0,"bb_sw=1;3g_sw=1;lte_l1_sw=1;digrfx=1;3g_dsp=1","bb_sw=sdl:th,tr,st,pr,mo,lt,db,li,syfts:xllt(gprs,umts),mon(gprs,umts),sdl(gprs,umts),llt(gprs,umts)|egdci:0x00000001|lte_stk:0x02,0x83FFFFFF|ims:1|lte_stk:0x01,0xFFFFFFFF,0xFFFFFFFF,0xFFFFFFFF,0xFFFFFFFFxllt:xllt_set_template(1,{basic});digrfx=0x0003;lte_l1_sw=(ALL,NORMAL,ALL,ALL)","oct=4;oct_fcs=16"
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App>
AT+XSYSTRACE=0,"bb_sw=1;3g_sw=1;lte_l1_sw=1;digrfx=1;3g_dsp=1","bb_sw=sdl:th,tr,st,pr,mo,lt,db,li,syfts:xllt(gprs,umts),mon(gprs,umts),sdl(gprs,umts),llt(gprs,umts)|egdci:0x00000001|lte_stk:0x02,0x83FFFFFF|ims:1|lte_stk:0x01,0xFFFFFFFF,0xFFFFFFFF,0xFFFFFFFF,0xFFFFFFFFxllt:xllt_set_template(1,{basic});digrfx=0x0003;lte_l1_sw=(ALL,NORMAL,ALL,ALL)","oct=4;oct_fcs=16"\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
So I'm suspecting that somehow the extra empty line from AT+XSYSTRACE=40 ends up as
the response for the AT+XSYSTRACE=50, but as it is not an OK it expects more, which for
some reason isn't read... Don't know why...
Here is my full callback source btw:
static void trace_start_at_cb(gboolean ok, GAtResult *result, gpointer user_data)
{
struct verimalto_data *data = user_data;
DBusMessage *reply;
DBG("");
if (!ok)
goto error;
switch (data->trace->step) {
case 1:
data->trace->step++;
g_at_chat_send(data->app, "AT+XSYSTRACE=40", none_prefix, trace_start_at_cb,
data, NULL);
break;
case 2:
data->trace->step++;
g_at_chat_send(data->app, "AT+XSYSTRACE=50", none_prefix, trace_start_at_cb,
data, NULL);
break;
case 3:
DBG("Trace cmd: %s", data->trace->mask_cmd);
g_at_chat_send(data->app, data->trace->mask_cmd, none_prefix, NULL, data, NULL);
g_free(data->trace->mask_cmd);
data->trace->mask_cmd = NULL;
reply = dbus_message_new_method_return(data->trace->msg);
__ofono_dbus_pending_reply(&data->trace->msg, reply);
break;
}
return;
error:
g_free(data->trace->mask_cmd);
data->trace->mask_cmd = NULL;
__ofono_dbus_pending_reply(&data->info->msg,
__ofono_error_failed(data->info->msg));
}
/Mattias
________________________________
Från: Mattias Månsson
Skickat: den 20 juni 2018 15:33:05
Till: Denis Kenzior; ofono(a)ofono.org
Ämne: SV: SV: Handling empty row from AT command
I will do some experiments and come back to you with logs...
________________________________
Från: Denis Kenzior <denkenz(a)gmail.com>
Skickat: den 20 juni 2018 15:30:00
Till: Mattias Månsson; ofono(a)ofono.org
Ämne: Re: SV: Handling empty row from AT command
Hi Mattias,
On 06/20/2018 08:24 AM, Mattias Månsson wrote:
It seems we already use that parser though:
syntax = g_at_syntax_new_gsm_permissive();
chat = g_at_chat_new(channel, syntax);
Not sure then. Permissive should be taking care of the issue you
describe, e.g it skips any empty lines:
case GSM_PERMISSIVE_STATE_IDLE:
if (byte == '\r' || byte == '\n')
/* ignore */;
Maybe there's something more subtle going on? Are there stray
whitespace characters or something else in the spurious response? You
would have to trace why the permissive syntax fails and either fix it or
design your own.
Regards,
-Denis
12:28 a.m.
New subject: SV: SV: Handling empty row from AT command
Hi Mattias,
By the way, please no top-posting on this list.
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: AppFinally woke up the modem
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=30\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]:
plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=40\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nDecoder List 0
bytes sent\r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]:
plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=50\r
So this tells me that XSYSTRACE=40 command response was processed
correctly (e.g. OK was detected) and we start the XSYSTRACE=50 command.
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\n\r\n
This tells me the modem is buggered and isn't responding with anything
resembling a 'proper' response. The AT trace will still show anything
that is being sent on the serial port, so if there's no 'OK' showing up,
there isn't much that oFono can do.
But if I skip the AT+XSYSTRACE=40, the sequence runs fine:
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: AppFinally woke up the modem
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT+XSYSTRACE=30\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]:
plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT+XSYSTRACE=50\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]:
Right, so something in the earlier XSYSTRACE sequence is screwing up the
firmware. Get your vendor on the line.
So I'm suspecting that somehow the extra empty line from AT+XSYSTRACE=40
ends up as the response for the AT+XSYSTRACE=50, but as it is not an OK
it expects more, which for some reason isn't read... Don't know why...
Nope. The socket is read and data is printed to debug output regardless
of what the syntax state is. See gatio.c:received_data()
Regards,
-Denis
12:30 a.m.
New subject: SV: SV: SV: Handling empty row from AT command
OK, thanks! I will talk to them :)
________________________________
Från: Denis Kenzior <denkenz(a)gmail.com>
Skickat: den 20 juni 2018 16:28:12
Till: Mattias Månsson; ofono(a)ofono.org
Ämne: Re: SV: SV: Handling empty row from AT command
Hi Mattias,
By the way, please no top-posting on this list.
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: AppFinally woke up the modem
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=30\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]:
plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=40\r
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\nDecoder List 0
bytes sent\r\nOK\r\n
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]:
plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App> AT+XSYSTRACE=50\r
So this tells me that XSYSTRACE=40 command response was processed
correctly (e.g. OK was detected) and we start the XSYSTRACE=50 command.
Jun 20 13:44:03 lev-26e7jvbe ofonod[16440]: App< \r\n\r\n
This tells me the modem is buggered and isn't responding with anything
resembling a 'proper' response. The AT trace will still show anything
that is being sent on the serial port, so if there's no 'OK' showing up,
there isn't much that oFono can do.
But if I skip the AT+XSYSTRACE=40, the sequence runs fine:
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: AppFinally woke up the modem
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT+XSYSTRACE=30\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]:
plugins/verimalto.c:trace_start_at_cb()
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App> AT+XSYSTRACE=50\r
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]: App< \r\nOK\r\n
Jun 20 13:54:04 lev-26e7jvbe ofonod[16598]:
Right, so something in the earlier XSYSTRACE sequence is screwing up the
firmware. Get your vendor on the line.
So I'm suspecting that somehow the extra empty line from AT+XSYSTRACE=40
ends up as the response for the AT+XSYSTRACE=50, but as it is not an OK
it expects more, which for some reason isn't read... Don't know why...
Nope. The socket is read and data is printed to debug output regardless
of what the syntax state is. See gatio.c:received_data()
Regards,
-Denis
1551
days inactive
1551
days old
7 comments
2 participants
participants (2)
-
Denis Kenzior -
Mattias Månsson