AT+VTS=$num should not wait for an answer

[GNUtoo]

DTMF fails to work: in the AT manual (27007-3d0.doc ) it says that +VTS doesn't expect a response, and indeed in the gta04 option modem it seem not to expect that.

So I tried to remove what makes fsogsmd wait for a response but I failed:

In fsogsmd/src/lib/at/atcallmediators.vala I did the following without success:

public class AtCallSendDtmf : CallSendDtmf
{
         public override async void run( string tones ) throws 
FreeSmartphone.GSM.Error, FreeSmartphone.Error

     {
         var cmd = theModem.createAtCommand<PlusVTS>( "+VTS" );
-        var response = yield theModem.processAtCommandAsync( cmd, cmd.issue( 
tones ) );
-        checkResponseOk( cmd, response );
+        yield theModem.processAtCommandAsync( cmd, cmd.issue( tones ) );
     }
}

Denis.

[morphis]

Possible solution is found in the bug/669-at+vts-should-not-wait-for-answer branch (​http://git.freesmartphone.org/?p=cornucopia.git;a=shortlog;h=refs/heads/bug/669-at%2Bvts-should-not-wait-for-answer). Needs testing and further investigation.

[GNUtoo]

That didn't work. I tried harder to make the branch work with the following patch to libfsotransport:

diff --git a/libfsotransport/fsotransport/commandqueue.vala b/libfsotransport/fsotransport/commandqueue.vala
index 1aaa90d..8cf457a 100644
--- a/libfsotransport/fsotransport/commandqueue.vala
+++ b/libfsotransport/fsotransport/commandqueue.vala
@@ -103,10 +103,13 @@ public abstract class FsoFramework.AbstractCommandQueue : FsoFramework.CommandQu
         assert( transport.logger.debug( @"Attemping to write next command to transport; we have $(q.size) com
         current = q.poll_head();
         current.writeToTransport( transport );
-        assert( transport.logger.debug( @"Wrote '$current'. Waiting ($(current.timeout)s) for answer..." ) );
-        if ( current.timeout > 0 )
-        {
-            timeoutWatch = GLib.Timeout.add_seconds( current.timeout, onTimeout );
+       if (current.callback != null)
+       {
+            assert( transport.logger.debug( @"Wrote '$current'. Waiting ($(current.timeout)s) for answer..." 
+            if ( current.timeout > 0 )
+            {
+                 timeoutWatch = GLib.Timeout.add_seconds( current.timeout, onTimeout );
+            }
         }
     }

But that produced the following log:

2012-03-26T15:25:32.710480Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: SRC: "D4200;" -> [ "OK" ]
2012-03-26T15:25:32.710937Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status
2012-03-26T15:25:32.711120Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallListCalls
2012-03-26T15:25:32.713470Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Attemping to write next command to transport; we have 1 commands pending!
2012-03-26T15:25:32.713684Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Wrote '+CLCC'. Waiting (5s) for answer...
2012-03-26T15:25:32.713867Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback called with 9 bytes in buffer
2012-03-26T15:25:32.713989Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback wrote 9 bytes
2012-03-26T15:25:32.717193Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: SRC: "+CLCC" -> [ "+CLCC: 1,0,2,0,0,"4200",129", "OK" ]
2012-03-26T15:25:32.718017Z [DEBUG] Gtm601Modem <>: Did receive a valid response for FsoGsmPlusCLCC
2012-03-26T15:25:32.718201Z [DEBUG] FsoGsmGenericAtCallHandler <>: 1 calls known in the system
2012-03-26T15:25:35.969665Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status
2012-03-26T15:25:35.969940Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallListCalls
2012-03-26T15:25:35.970245Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Attemping to write next command to transport; we have 1 commands pending!
2012-03-26T15:25:35.970398Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Wrote '+CLCC'. Waiting (5s) for answer...
2012-03-26T15:25:35.970550Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback called with 9 bytes in buffer
2012-03-26T15:25:35.970764Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback wrote 9 bytes
2012-03-26T15:25:36.053863Z [INFO]  libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: URC: [ "+CSSI: 1" ]
2012-03-26T15:25:36.054077Z [DEBUG] Gtm601UnsolicitedResponseHandler : Dispatching AT unsolicited '+CSSI', '1'
2012-03-26T15:25:36.054291Z [DEBUG] Gtm601Modem <>: Did receive a valid response for FsoGsmPlusCSSI
2012-03-26T15:25:36.054718Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: SRC: "+CLCC" -> [ "+CLCC: 1,0,0,0,0,"4200",129", "OK" ]
2012-03-26T15:25:36.054962Z [DEBUG] Gtm601Modem <>: Did receive a valid response for FsoGsmPlusCLCC
2012-03-26T15:25:36.055115Z [DEBUG] FsoGsmGenericAtCallHandler <>: 1 calls known in the system
2012-03-26T15:25:38.970856Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status
2012-03-26T15:25:38.971130Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallListCalls
2012-03-26T15:25:38.971435Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Attemping to write next command to transport; we have 1 commands pending!
2012-03-26T15:25:38.971588Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Wrote '+CLCC'. Waiting (5s) for answer...
2012-03-26T15:25:38.971741Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback called with 9 bytes in buffer
2012-03-26T15:25:38.971954Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback wrote 9 bytes
2012-03-26T15:25:39.057800Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: SRC: "+CLCC" -> [ "+CLCC: 1,0,0,0,0,"4200",129", "OK" ]
2012-03-26T15:25:39.058197Z [DEBUG] Gtm601Modem <>: Did receive a valid response for FsoGsmPlusCLCC
2012-03-26T15:25:39.058319Z [DEBUG] FsoGsmGenericAtCallHandler <>: 1 calls known in the system
2012-03-26T15:25:41.970764Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status
2012-03-26T15:25:41.971039Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallListCalls
2012-03-26T15:25:41.971313Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Attemping to write next command to transport; we have 1 commands pending!
2012-03-26T15:25:41.971466Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Wrote '+CLCC'. Waiting (5s) for answer...
2012-03-26T15:25:41.971618Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback called with 9 bytes in buffer
2012-03-26T15:25:41.971832Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback wrote 9 bytes
2012-03-26T15:25:42.066803Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: SRC: "+CLCC" -> [ "+CLCC: 1,0,0,0,0,"4200",129", "OK" ]
2012-03-26T15:25:42.067200Z [DEBUG] Gtm601Modem <>: Did receive a valid response for FsoGsmPlusCLCC
2012-03-26T15:25:42.067322Z [DEBUG] FsoGsmGenericAtCallHandler <>: 1 calls known in the system
2012-03-26T15:25:44.970276Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status
2012-03-26T15:25:44.970550Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallListCalls
2012-03-26T15:25:44.970856Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Attemping to write next command to transport; we have 1 commands pending!
2012-03-26T15:25:44.971008Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Wrote '+CLCC'. Waiting (5s) for answer...
2012-03-26T15:25:44.971313Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback called with 9 bytes in buffer
2012-03-26T15:25:44.971527Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback wrote 9 bytes
2012-03-26T15:25:45.055786Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: SRC: "+CLCC" -> [ "+CLCC: 1,0,0,0,0,"4200",129", "OK" ]
2012-03-26T15:25:45.056183Z [DEBUG] Gtm601Modem <>: Did receive a valid response for FsoGsmPlusCLCC
2012-03-26T15:25:45.056305Z [DEBUG] FsoGsmGenericAtCallHandler <>: 1 calls known in the system
2012-03-26T15:25:45.791565Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallSendDtmf
2012-03-26T15:25:45.798401Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: Attemping to write next command to transport; we have 1 commands pending!
2012-03-26T15:25:45.798706Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback called with 10 bytes in buffer
2012-03-26T15:25:45.798858Z [DEBUG] libfsotransport <Serial /dev/ttyHS3@115200 (fd 20)>: WriteCallback wrote 10 bytes
2012-03-26T15:25:47.970550Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status
2012-03-26T15:25:47.970825Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallListCalls
2012-03-26T15:25:50.967743Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status not done yet... ignoring
2012-03-26T15:25:53.967621Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status not done yet... ignoring
2012-03-26T15:25:56.967621Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status not done yet... ignoring
2012-03-26T15:25:58.891540Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallSendDtmf
2012-03-26T15:25:59.967590Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status not done yet... ignoring
2012-03-26T15:26:02.354675Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallRelease
2012-03-26T15:26:02.973450Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status not done yet... ignoring
2012-03-26T15:26:03.898987Z [DEBUG] Gtm601Modem <>: Created mediator FsoGsmCallRelease
2012-03-26T15:26:05.967743Z [DEBUG] FsoGsmGenericAtCallHandler <>: Synchronizing call status not done yet... ignoring

which is translated into the fact that after issuing AT+VTS=9, no other commands work.

Denis.

[morphis]

To reproduce the bug:

<GNUtoo-desktop> I ran SHR image
<GNUtoo-desktop> and I called 4242(an operator number)
<GNUtoo-desktop> I pressed a button(9 for instance)
<GNUtoo-desktop> and it kept repeating AT+VTS=9

[morphis]

I implemented a working "solution" now in the bugs/669-at+vts-should-not-wait-for-answer branch but I am unhappy with this. Regarding 27.007 AT+VTS doesn't expect a response but get one in case you're sending it in the wrong state (no call is active or wrong character) which is now being tracked in fsogsmd's log as

2012-04-19T08:52:00.036953Z [DEBUG] Gtm601UnsolicitedResponseHandler : Dispatching AT unsolicited 'ERROR', ''
2012-04-19T08:52:00.037017Z [WARN]  Gtm601Modem <>: No handler for URC ERROR w/ rhs , please report to Mickey <smartphones-userland@linuxtogo.org>

In production environment we're checking each tone supplied for org.freesmartphone.GSM.Call.SendDtmf? before sending it to the modem, so this should hopefully never happen ...

I will experiment a little bit more before I decide how we solve this bug finally.

[morphis]

It's now fixed with commit 9aec54f7153db7dd510d2f48c5556bdc85f47ec7

I tested this with the GTA04A4 calling another phone. When I send a AT+VTS command they were sent immediately without waiting for a response and on the other side I heard the tones.