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; [email protected]
Ä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 <[email protected]>
Skickat: den 20 juni 2018 15:30:00
Till: Mattias Månsson; [email protected]
Ä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
_______________________________________________
ofono mailing list
[email protected]
https://lists.ofono.org/mailman/listinfo/ofono
