Hello Patrick,
It seems to me that the client gets confused here. If it cannot suspend,
it should simply complete the session.
I agree with your diagnosis - if it is too late for a client to suspend it
should terminate the session normally, and not do the kind of abort the log
shows here.
There's IMHO one reason for too late - if the client is about to send the
last message (final message of map phase), it does not make sense to request a
suspend.
From the log snippets alone I can't see if it's really that case, but I guess
so. Do you have complete HTML logs of this test case?
Most probably, there should be an extra check for that too late suspend.
I'm a bit unsure about how to call SessionStep() after asking for a
suspend. I think we observed that it was waiting for the server reply,
so we call it with GOTDATA. The sequence is this (before is what is
passed to the function, after what it sets):
STEPCMD_SUSPEND is an out of order step, and can be issued anywhere in
between. It always returns STEPCMD_OK. After issuing a STEPCMD_SUSPEND, you
should continue stepping exactly as if the STEPCMD_SUSPEND had never happened.
There's a note on this in engine_defs.h:249, but probably also should be
mentioned in the SDK docs.
Best Regards,
Lukas
On Feb 26, 2010, at 14:58 , Patrick Ohly wrote:
Hello!
I'm testing suspend/resume between SyncEvolution as client and as
server. Our test suite contains a test which runs different sync
scenarios and asks to suspend on the client side before processing each
server reply, at all those positions (before first reply, second, etc.).
I notice that it fails when the client suspends before processing the
second-to-last server reply (in other words, before the final message
from the client to the server).
I'm attaching that client log. What I see is this (initial messages from
SyncEvolution):
* [2010-02-26 13:56:21.885] UserSuspendInjector: user suspend
after getting reply #2
* [2010-02-26 13:56:21.885] suspending before SessionStep() in
STEPCMD_GOTDATA as requested by user
* [2010-02-26 13:56:21.885] --- Ignoring all commands in
this message (after 1 sec. request processing, 1 sec. total) with
Status 514 (0=none) from here on
* [2010-02-26 13:56:21.885] WARNING: Session locally flagged for
suspend, reason=20032
* [2010-02-26 13:56:21.885] suspending before SessionStep() in
STEPCMD_GOTDATA as requested by user
* [2010-02-26 13:56:21.885] engine already notified of suspend
request, reverting to STEPCMD_GOTDATA
...
* [2010-02-26 13:56:21.888] Outgoing WBXML message msgID=4 saved as XML
translation
...
* [2010-02-26 13:56:21.889] Warning: Failed with status code=0,
statistics are incomplete!!
...
* [2010-02-26 13:56:21.889] Session not any more in progress:
NextMessage() returns OK status=0
* [2010-02-26 13:56:21.889] forgetChangeLog: DISCARDING already loaded
changelog with 7 entries
* [2010-02-26 13:56:21.890] DeleteContext
* [2010-02-26 13:56:21.890] TSyncSession::TerminateSession: calling
InternalResetSession
* [2010-02-26 13:56:21.890] Never received status for command
'SyncHdr', (outgoing MsgID=4, CmdID=0)
* [2010-02-26 13:56:21.890] Deleted command 'SyncHdr' (outgoing
MsgID=4, CmdID=0)
That last outgoing message is also attached. It does *not* contain a
request to suspend, but the client seems to think that is has suspended.
It does not save its anchors. The server sees that last message and
completes its session normally, saving the next client anchor. In the
following session, the client anchor mismatch forces a slow sync.
It seems to me that the client gets confused here. If it cannot suspend,
it should simply complete the session.
I'm a bit unsure about how to call SessionStep() after asking for a
suspend. I think we observed that it was waiting for the server reply,
so we call it with GOTDATA. The sequence is this (before is what is
passed to the function, after what it sets):
* [2010-02-26 14:51:26.073] after SessionStep: STEPCMD_NEEDDATA
* [2010-02-26 14:51:26.073] UserSuspendInjector: user suspend after
getting reply #2
* [2010-02-26 14:51:26.073] suspending before SessionStep() in
STEPCMD_GOTDATA as requested by user
* [2010-02-26 14:51:26.073] before SessionStep: STEPCMD_SUSPEND
* [2010-02-26 14:51:26.073] --- Ignoring all commands in
this message (after 1 sec. request processing, 1 sec. total) with
Status 514 (0=none) from here on
* [2010-02-26 14:51:26.073] WARNING: Session locally flagged for
suspend, reason=20032
* [2010-02-26 14:51:26.073] after SessionStep: STEPCMD_OK
* [2010-02-26 14:51:26.073] suspending before SessionStep() in
STEPCMD_GOTDATA as requested by user
* [2010-02-26 14:51:26.074] engine already notified of suspend
request, reverting to STEPCMD_GOTDATA
* [2010-02-26 14:51:26.074] before SessionStep: STEPCMD_GOTDATA
* [2010-02-26
