merged in default ENGINE-155
authorKrista Grothoff <krista@pep-project.org>
Thu, 15 Dec 2016 18:00:28 +0100
branchENGINE-155
changeset 149340b1e72d1d89
parent 1491 317329e61148
parent 1492 cc9037bf19d2
child 1497 5c110c844ff5
merged in default
     1.1 --- a/src/keymanagement.c	Thu Dec 15 14:06:53 2016 +0100
     1.2 +++ b/src/keymanagement.c	Thu Dec 15 18:00:28 2016 +0100
     1.3 @@ -292,7 +292,7 @@
     1.4      free(identity->user_id);
     1.5      identity->user_id = strdup(temp_id->user_id);
     1.6      free(identity->username);
     1.7 -    identity->username = strdup(temp_id->username);
     1.8 +    identity->username = strdup(temp_id->username ? temp_id->username : "anonymous");
     1.9      identity->comm_type = temp_id->comm_type;
    1.10      identity->lang[0] = temp_id->lang[0];
    1.11      identity->lang[1] = temp_id->lang[1];
    1.12 @@ -438,6 +438,15 @@
    1.13              return PEP_OUT_OF_MEMORY;
    1.14      }
    1.15  
    1.16 +    if (EMPTYSTR(identity->username))
    1.17 +    {
    1.18 +        free(identity->username);
    1.19 +        identity->username = strdup("anonymous");
    1.20 +        assert(identity->username);
    1.21 +        if (identity->username == NULL)
    1.22 +            return PEP_OUT_OF_MEMORY;
    1.23 +    }
    1.24 +
    1.25      DEBUG_LOG("myself", "debug", identity->address);
    1.26   
    1.27      status = get_identity(session,
     2.1 --- a/src/sync.h	Thu Dec 15 14:06:53 2016 +0100
     2.2 +++ b/src/sync.h	Thu Dec 15 18:00:28 2016 +0100
     2.3 @@ -5,7 +5,7 @@
     2.4  
     2.5  In the engine, KeySync is implemented through a state machine [1]. KeySync
     2.6  state machine is driven [2] by events, triggering actions [3] and transitions
     2.7 -to new states. Events happens on decryption of email messages, on key
     2.8 +to new states. Events happen on decryption of email messages, on key
     2.9  generation, on user interaction through the app and in case of timeout when
    2.10  staying too long in some particular states.
    2.11  
    2.12 @@ -26,7 +26,7 @@
    2.13  collected from decrypted messages. They are jobs to be processed by the state
    2.14  machine.
    2.15  
    2.16 -KeySync messages can be emitted by multiple session, and could naturally come
    2.17 +KeySync messages can be emitted by multiple sessions, and could naturally come
    2.18  from different threads. They must be serialized in a locked queue. Attached
    2.19  sessions inject [8] KeySync messages in the queue. Protocol loop retrieves [9]
    2.20  them from the queue. KeySync message is received [10] by the state machine,
    2.21 @@ -38,7 +38,7 @@
    2.22  passed as a parameter of the call to the blocking queue retrieve operation on 
    2.23  next protocol loop iteraton.
    2.24  
    2.25 -[1] sync/device_group.fsm , src/sync_fsm.c (generated)
    2.26 +[1] sync/devicegroup.fsm , src/sync_fsm.c (generated)
    2.27  [2] src/sync_driver.c (generated)
    2.28  [3] src/sync_actions.c , src/sync_send_actions.c (generated)
    2.29  [4] register_sync_callbacks()
     3.1 --- a/sync/gen_statemachine.ysl2	Thu Dec 15 14:06:53 2016 +0100
     3.2 +++ b/sync/gen_statemachine.ysl2	Thu Dec 15 18:00:28 2016 +0100
     3.3 @@ -217,8 +217,9 @@
     3.4          `` if "count(parm) > 1" error | # TODO composite state payload 
     3.5          `` apply "parm", 1 mode="stateParm"
     3.6          *timeout = «@timeout»;
     3.7 +        DEBUG_LOG("Entering FSM state", "«../@filename»_fsm.c", "state=«@name»")
     3.8          switch (event) {
     3.9 -        `` if "not(event[@name='Init'])" |>> case Init: break;
    3.10 +        `` if "not(event[@name='Init'])" |>> case Init: DEBUG_LOG("FSM event", "«../@filename»_fsm.c, state=«@name»", "event=Init") break;
    3.11          `` apply "event", 2
    3.12              default:
    3.13                  return («../@name»_state) invalid_event;
    3.14 @@ -236,12 +237,14 @@
    3.15      ||
    3.16      case «@name»:
    3.17      {
    3.18 +        DEBUG_LOG("FSM event", "«../../@filename»_fsm.c, state=«../@name»", "event=«@name»")
    3.19      `` apply "action|transition|condition";
    3.20      `` if "name(*[position()=last()]) != 'transition'" |> break;
    3.21      }
    3.22      ||
    3.23  
    3.24      template "action" {
    3.25 +        | DEBUG_LOG("FSM action", "«ancestor::fsm/@filename»_fsm.c, state=«ancestor::state/@name», event=«ancestor::event/@name»", "action=«@name»")
    3.26          indent(0);
    3.27          > status = «@name»(session, state, 
    3.28          choose {
    3.29 @@ -261,6 +264,11 @@
    3.30  
    3.31      template "condition" {
    3.32          | cond_result = «@name»(session`apply "parm", 0`);
    3.33 +        | #ifndef NDEBUG
    3.34 +        | char resstr[11] = {0,};
    3.35 +        | snprintf(resstr,10,"result=%d",cond_result);
    3.36 +        | #endif
    3.37 +        | DEBUG_LOG("FSM condition", "«ancestor::fsm/@filename»_fsm.c, state=«ancestor::state/@name», event=«ancestor::event/@name», condition=«@name»", resstr)
    3.38          | if (cond_result < 0)
    3.39          |> return cond_result;
    3.40          | if (cond_result) {
    3.41 @@ -294,6 +302,7 @@
    3.42              const "nextstateparm", "ancestor::fsm/child::state[@name = $nextstatename]/child::parm";
    3.43              | session->sync_state_payload = «yml:lcase(name($nextstateparm/*))»_dup(«name(parm/*)»);
    3.44          }
    3.45 +        | DEBUG_LOG("FSM transition", "«ancestor::fsm/@filename»_fsm.c, state=«ancestor::state/@name», event=«ancestor::event/@name»", "target=«@target»")
    3.46          | return «@target»;
    3.47      }
    3.48  }
     4.1 --- a/sync/generated/sync_fsm.c	Thu Dec 15 14:06:53 2016 +0100
     4.2 +++ b/sync/generated/sync_fsm.c	Thu Dec 15 18:00:28 2016 +0100
     4.3 @@ -19,15 +19,24 @@
     4.4          case InitState:
     4.5          {
     4.6              *timeout = 0;
     4.7 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=InitState")
     4.8              switch (event) {
     4.9                  case Init:
    4.10                  {
    4.11 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=InitState", "event=Init")
    4.12                      cond_result = storedGroupKeys(session);
    4.13 +                    #ifndef NDEBUG
    4.14 +                    char resstr[11] = {0,};
    4.15 +                    snprintf(resstr,10,"result=%d",cond_result);
    4.16 +                    #endif
    4.17 +                    DEBUG_LOG("FSM condition", "sync_fsm.c, state=InitState, event=Init, condition=storedGroupKeys", resstr)
    4.18                      if (cond_result < 0)
    4.19                          return cond_result;
    4.20                      if (cond_result) {
    4.21 +                        DEBUG_LOG("FSM transition", "sync_fsm.c, state=InitState, event=Init", "target=Grouped")
    4.22                          return Grouped;
    4.23                      }
    4.24 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=InitState, event=Init", "target=Sole")
    4.25                      return Sole;
    4.26                  }
    4.27                  default:
    4.28 @@ -38,10 +47,13 @@
    4.29          case Sole:
    4.30          {
    4.31              *timeout = 0;
    4.32 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=Sole")
    4.33              switch (event) {
    4.34 -                case Init: break;
    4.35 +                case Init: DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=Init") break;
    4.36                  case KeyGen:
    4.37                  {
    4.38 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=KeyGen")
    4.39 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=KeyGen", "action=sendBeacon")
    4.40                      status = sendBeacon(session, state, NULL, NULL);
    4.41                      if (status == PEP_OUT_OF_MEMORY)
    4.42                          return (int) invalid_out_of_memory;
    4.43 @@ -51,6 +63,8 @@
    4.44                  }
    4.45                  case CannotDecrypt:
    4.46                  {
    4.47 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=CannotDecrypt")
    4.48 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=CannotDecrypt", "action=sendBeacon")
    4.49                      status = sendBeacon(session, state, NULL, NULL);
    4.50                      if (status == PEP_OUT_OF_MEMORY)
    4.51                          return (int) invalid_out_of_memory;
    4.52 @@ -60,6 +74,8 @@
    4.53                  }
    4.54                  case Beacon:
    4.55                  {
    4.56 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=Beacon")
    4.57 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=Beacon", "action=sendHandshakeRequest")
    4.58                      status = sendHandshakeRequest(session, state, partner, NULL);
    4.59                      if (status == PEP_OUT_OF_MEMORY)
    4.60                          return (int) invalid_out_of_memory;
    4.61 @@ -69,12 +85,15 @@
    4.62                  }
    4.63                  case HandshakeRequest:
    4.64                  {
    4.65 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=HandshakeRequest")
    4.66 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=HandshakeRequest", "action=sendHandshakeRequest")
    4.67                      status = sendHandshakeRequest(session, state, partner, NULL);
    4.68                      if (status == PEP_OUT_OF_MEMORY)
    4.69                          return (int) invalid_out_of_memory;
    4.70                      if (status != PEP_STATUS_OK)
    4.71                          return (int) invalid_action;
    4.72                      session->sync_state_payload = identity_dup(partner);
    4.73 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=Sole, event=HandshakeRequest", "target=HandshakingSole")
    4.74                      return HandshakingSole;
    4.75                  }
    4.76                  default:
    4.77 @@ -86,13 +105,21 @@
    4.78          {
    4.79              Identity expected = (Identity)session->sync_state_payload;
    4.80              *timeout = 600;
    4.81 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=HandshakingSole")
    4.82              switch (event) {
    4.83                  case Init:
    4.84                  {
    4.85 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=Init")
    4.86                      cond_result = keyElectionWon(session, partner);
    4.87 +                    #ifndef NDEBUG
    4.88 +                    char resstr[11] = {0,};
    4.89 +                    snprintf(resstr,10,"result=%d",cond_result);
    4.90 +                    #endif
    4.91 +                    DEBUG_LOG("FSM condition", "sync_fsm.c, state=HandshakingSole, event=Init, condition=keyElectionWon", resstr)
    4.92                      if (cond_result < 0)
    4.93                          return cond_result;
    4.94                      if (cond_result) {
    4.95 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=Init", "action=notifyInitFormGroup")
    4.96                          status = notifyInitFormGroup(session, state, partner, NULL);
    4.97                          if (status == PEP_OUT_OF_MEMORY)
    4.98                              return (int) invalid_out_of_memory;
    4.99 @@ -100,6 +127,7 @@
   4.100                              return (int) invalid_action;
   4.101                      }
   4.102                      else {
   4.103 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=Init", "action=notifyInitAddOurDevice")
   4.104                          status = notifyInitAddOurDevice(session, state, partner, NULL);
   4.105                          if (status == PEP_OUT_OF_MEMORY)
   4.106                              return (int) invalid_out_of_memory;
   4.107 @@ -110,6 +138,8 @@
   4.108                  }
   4.109                  case HandshakeRejected:
   4.110                  {
   4.111 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=HandshakeRejected")
   4.112 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeRejected", "action=rejectHandshake")
   4.113                      status = rejectHandshake(session, state, partner, NULL);
   4.114                      if (status == PEP_OUT_OF_MEMORY)
   4.115                          return (int) invalid_out_of_memory;
   4.116 @@ -119,24 +149,34 @@
   4.117                          free_identity((Identity)session->sync_state_payload);
   4.118                          session->sync_state_payload = NULL;
   4.119                      }
   4.120 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=HandshakeRejected", "target=Sole")
   4.121                      return Sole;
   4.122                  }
   4.123                  case HandshakeAccepted:
   4.124                  {
   4.125 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=HandshakeAccepted")
   4.126 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "action=acceptHandshake")
   4.127                      status = acceptHandshake(session, state, partner, NULL);
   4.128                      if (status == PEP_OUT_OF_MEMORY)
   4.129                          return (int) invalid_out_of_memory;
   4.130                      if (status != PEP_STATUS_OK)
   4.131                          return (int) invalid_action;
   4.132                      cond_result = keyElectionWon(session, partner);
   4.133 +                    #ifndef NDEBUG
   4.134 +                    char resstr[11] = {0,};
   4.135 +                    snprintf(resstr,10,"result=%d",cond_result);
   4.136 +                    #endif
   4.137 +                    DEBUG_LOG("FSM condition", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted, condition=keyElectionWon", resstr)
   4.138                      if (cond_result < 0)
   4.139                          return cond_result;
   4.140                      if (cond_result) {
   4.141 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "action=sendGroupKeys")
   4.142                          status = sendGroupKeys(session, state, partner, NULL);
   4.143                          if (status == PEP_OUT_OF_MEMORY)
   4.144                              return (int) invalid_out_of_memory;
   4.145                          if (status != PEP_STATUS_OK)
   4.146                              return (int) invalid_action;
   4.147 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "action=notifyAcceptedGroupCreated")
   4.148                          status = notifyAcceptedGroupCreated(session, state, partner, NULL);
   4.149                          if (status == PEP_OUT_OF_MEMORY)
   4.150                              return (int) invalid_out_of_memory;
   4.151 @@ -146,6 +186,7 @@
   4.152                              free_identity((Identity)session->sync_state_payload);
   4.153                              session->sync_state_payload = NULL;
   4.154                          }
   4.155 +                        DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "target=Grouped")
   4.156                          return Grouped;
   4.157                      }
   4.158                      if(session->sync_state_payload){
   4.159 @@ -153,18 +194,23 @@
   4.160                          session->sync_state_payload = NULL;
   4.161                      }
   4.162                      session->sync_state_payload = identity_dup(partner);
   4.163 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "target=WaitForGroupKeysSole")
   4.164                      return WaitForGroupKeysSole;
   4.165                  }
   4.166                  case Cancel:
   4.167                  {
   4.168 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=Cancel")
   4.169                      if(session->sync_state_payload){
   4.170                          free_identity((Identity)session->sync_state_payload);
   4.171                          session->sync_state_payload = NULL;
   4.172                      }
   4.173 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=Cancel", "target=Sole")
   4.174                      return Sole;
   4.175                  }
   4.176                  case Timeout:
   4.177                  {
   4.178 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=Timeout")
   4.179 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=Timeout", "action=notifyTimeout")
   4.180                      status = notifyTimeout(session, state, expected, NULL);
   4.181                      if (status == PEP_OUT_OF_MEMORY)
   4.182                          return (int) invalid_out_of_memory;
   4.183 @@ -174,6 +220,7 @@
   4.184                          free_identity((Identity)session->sync_state_payload);
   4.185                          session->sync_state_payload = NULL;
   4.186                      }
   4.187 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=Timeout", "target=Sole")
   4.188                      return Sole;
   4.189                  }
   4.190                  default:
   4.191 @@ -185,15 +232,19 @@
   4.192          {
   4.193              Identity expected = (Identity)session->sync_state_payload;
   4.194              *timeout = 600;
   4.195 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=WaitForGroupKeysSole")
   4.196              switch (event) {
   4.197 -                case Init: break;
   4.198 +                case Init: DEBUG_LOG("FSM event", "sync_fsm.c, state=WaitForGroupKeysSole", "event=Init") break;
   4.199                  case GroupKeys:
   4.200                  {
   4.201 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=WaitForGroupKeysSole", "event=GroupKeys")
   4.202 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=WaitForGroupKeysSole, event=GroupKeys", "action=storeGroupKeys")
   4.203                      status = storeGroupKeys(session, state, partner, extra /*keys*/);
   4.204                      if (status == PEP_OUT_OF_MEMORY)
   4.205                          return (int) invalid_out_of_memory;
   4.206                      if (status != PEP_STATUS_OK)
   4.207                          return (int) invalid_action;
   4.208 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=WaitForGroupKeysSole, event=GroupKeys", "action=notifyAcceptedDeviceAdded")
   4.209                      status = notifyAcceptedDeviceAdded(session, state, partner, NULL);
   4.210                      if (status == PEP_OUT_OF_MEMORY)
   4.211                          return (int) invalid_out_of_memory;
   4.212 @@ -203,10 +254,13 @@
   4.213                          free_identity((Identity)session->sync_state_payload);
   4.214                          session->sync_state_payload = NULL;
   4.215                      }
   4.216 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=WaitForGroupKeysSole, event=GroupKeys", "target=Grouped")
   4.217                      return Grouped;
   4.218                  }
   4.219                  case Timeout:
   4.220                  {
   4.221 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=WaitForGroupKeysSole", "event=Timeout")
   4.222 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=WaitForGroupKeysSole, event=Timeout", "action=notifyTimeout")
   4.223                      status = notifyTimeout(session, state, expected, NULL);
   4.224                      if (status == PEP_OUT_OF_MEMORY)
   4.225                          return (int) invalid_out_of_memory;
   4.226 @@ -216,6 +270,7 @@
   4.227                          free_identity((Identity)session->sync_state_payload);
   4.228                          session->sync_state_payload = NULL;
   4.229                      }
   4.230 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=WaitForGroupKeysSole, event=Timeout", "target=Sole")
   4.231                      return Sole;
   4.232                  }
   4.233                  default:
   4.234 @@ -226,9 +281,12 @@
   4.235          case Grouped:
   4.236          {
   4.237              *timeout = 0;
   4.238 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=Grouped")
   4.239              switch (event) {
   4.240                  case Init:
   4.241                  {
   4.242 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=Init")
   4.243 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=Init", "action=enterGroup")
   4.244                      status = enterGroup(session, state, NULL, NULL);
   4.245                      if (status == PEP_OUT_OF_MEMORY)
   4.246                          return (int) invalid_out_of_memory;
   4.247 @@ -238,6 +296,8 @@
   4.248                  }
   4.249                  case KeyGen:
   4.250                  {
   4.251 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=KeyGen")
   4.252 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=KeyGen", "action=sendGroupUpdate")
   4.253                      status = sendGroupUpdate(session, state, NULL, NULL);
   4.254                      if (status == PEP_OUT_OF_MEMORY)
   4.255                          return (int) invalid_out_of_memory;
   4.256 @@ -247,6 +307,8 @@
   4.257                  }
   4.258                  case CannotDecrypt:
   4.259                  {
   4.260 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=CannotDecrypt")
   4.261 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=CannotDecrypt", "action=sendUpdateRequest")
   4.262                      status = sendUpdateRequest(session, state, NULL, NULL);
   4.263                      if (status == PEP_OUT_OF_MEMORY)
   4.264                          return (int) invalid_out_of_memory;
   4.265 @@ -256,6 +318,8 @@
   4.266                  }
   4.267                  case UpdateRequest:
   4.268                  {
   4.269 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=UpdateRequest")
   4.270 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=UpdateRequest", "action=sendGroupUpdate")
   4.271                      status = sendGroupUpdate(session, state, NULL, NULL);
   4.272                      if (status == PEP_OUT_OF_MEMORY)
   4.273                          return (int) invalid_out_of_memory;
   4.274 @@ -265,6 +329,8 @@
   4.275                  }
   4.276                  case Beacon:
   4.277                  {
   4.278 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=Beacon")
   4.279 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=Beacon", "action=sendHandshakeRequest")
   4.280                      status = sendHandshakeRequest(session, state, partner, NULL);
   4.281                      if (status == PEP_OUT_OF_MEMORY)
   4.282                          return (int) invalid_out_of_memory;
   4.283 @@ -274,16 +340,21 @@
   4.284                  }
   4.285                  case HandshakeRequest:
   4.286                  {
   4.287 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=HandshakeRequest")
   4.288 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=HandshakeRequest", "action=sendHandshakeRequest")
   4.289                      status = sendHandshakeRequest(session, state, partner, NULL);
   4.290                      if (status == PEP_OUT_OF_MEMORY)
   4.291                          return (int) invalid_out_of_memory;
   4.292                      if (status != PEP_STATUS_OK)
   4.293                          return (int) invalid_action;
   4.294                      session->sync_state_payload = identity_dup(partner);
   4.295 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=Grouped, event=HandshakeRequest", "target=HandshakingGrouped")
   4.296                      return HandshakingGrouped;
   4.297                  }
   4.298                  case GroupUpdate:
   4.299                  {
   4.300 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=GroupUpdate")
   4.301 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=GroupUpdate", "action=storeGroupKeys")
   4.302                      status = storeGroupKeys(session, state, partner, extra /*keys*/);
   4.303                      if (status == PEP_OUT_OF_MEMORY)
   4.304                          return (int) invalid_out_of_memory;
   4.305 @@ -300,9 +371,12 @@
   4.306          {
   4.307              Identity expected = (Identity)session->sync_state_payload;
   4.308              *timeout = 600;
   4.309 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=HandshakingGrouped")
   4.310              switch (event) {
   4.311                  case Init:
   4.312                  {
   4.313 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=Init")
   4.314 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=Init", "action=notifyInitAddOurDevice")
   4.315                      status = notifyInitAddOurDevice(session, state, partner, NULL);
   4.316                      if (status == PEP_OUT_OF_MEMORY)
   4.317                          return (int) invalid_out_of_memory;
   4.318 @@ -312,6 +386,8 @@
   4.319                  }
   4.320                  case HandshakeRejected:
   4.321                  {
   4.322 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=HandshakeRejected")
   4.323 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeRejected", "action=rejectHandshake")
   4.324                      status = rejectHandshake(session, state, partner, NULL);
   4.325                      if (status == PEP_OUT_OF_MEMORY)
   4.326                          return (int) invalid_out_of_memory;
   4.327 @@ -321,15 +397,19 @@
   4.328                          free_identity((Identity)session->sync_state_payload);
   4.329                          session->sync_state_payload = NULL;
   4.330                      }
   4.331 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeRejected", "target=Grouped")
   4.332                      return Grouped;
   4.333                  }
   4.334                  case HandshakeAccepted:
   4.335                  {
   4.336 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=HandshakeAccepted")
   4.337 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeAccepted", "action=acceptHandshake")
   4.338                      status = acceptHandshake(session, state, partner, NULL);
   4.339                      if (status == PEP_OUT_OF_MEMORY)
   4.340                          return (int) invalid_out_of_memory;
   4.341                      if (status != PEP_STATUS_OK)
   4.342                          return (int) invalid_action;
   4.343 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeAccepted", "action=sendGroupKeys")
   4.344                      status = sendGroupKeys(session, state, partner, NULL);
   4.345                      if (status == PEP_OUT_OF_MEMORY)
   4.346                          return (int) invalid_out_of_memory;
   4.347 @@ -339,10 +419,13 @@
   4.348                          free_identity((Identity)session->sync_state_payload);
   4.349                          session->sync_state_payload = NULL;
   4.350                      }
   4.351 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeAccepted", "target=Grouped")
   4.352                      return Grouped;
   4.353                  }
   4.354                  case Timeout:
   4.355                  {
   4.356 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=Timeout")
   4.357 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=Timeout", "action=notifyTimeout")
   4.358                      status = notifyTimeout(session, state, expected, NULL);
   4.359                      if (status == PEP_OUT_OF_MEMORY)
   4.360                          return (int) invalid_out_of_memory;
   4.361 @@ -352,6 +435,7 @@
   4.362                          free_identity((Identity)session->sync_state_payload);
   4.363                          session->sync_state_payload = NULL;
   4.364                      }
   4.365 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingGrouped, event=Timeout", "target=Grouped")
   4.366                      return Grouped;
   4.367                  }
   4.368                  default: