added verbose sync FSM debug logging
authorEdouard Tisserant <edouard@pep-project.org>
Thu, 15 Dec 2016 15:43:14 +0100
changeset 1490e375c22bc587
parent 1489 e1a35c0169c0
child 1492 cc9037bf19d2
added verbose sync FSM debug logging
sync/gen_statemachine.ysl2
sync/generated/sync_fsm.c
     1.1 --- a/sync/gen_statemachine.ysl2	Wed Dec 14 17:27:30 2016 +0100
     1.2 +++ b/sync/gen_statemachine.ysl2	Thu Dec 15 15:43:14 2016 +0100
     1.3 @@ -217,8 +217,9 @@
     1.4          `` if "count(parm) > 1" error | # TODO composite state payload 
     1.5          `` apply "parm", 1 mode="stateParm"
     1.6          *timeout = «@timeout»;
     1.7 +        DEBUG_LOG("Entering FSM state", "«../@filename»_fsm.c", "state=«@name»")
     1.8          switch (event) {
     1.9 -        `` if "not(event[@name='Init'])" |>> case Init: break;
    1.10 +        `` if "not(event[@name='Init'])" |>> case Init: DEBUG_LOG("FSM event", "«../@filename»_fsm.c, state=«@name»", "event=Init") break;
    1.11          `` apply "event", 2
    1.12              default:
    1.13                  return («../@name»_state) invalid_event;
    1.14 @@ -236,12 +237,14 @@
    1.15      ||
    1.16      case «@name»:
    1.17      {
    1.18 +        DEBUG_LOG("FSM event", "«../../@filename»_fsm.c, state=«../@name»", "event=«@name»")
    1.19      `` apply "action|transition|condition";
    1.20      `` if "name(*[position()=last()]) != 'transition'" |> break;
    1.21      }
    1.22      ||
    1.23  
    1.24      template "action" {
    1.25 +        | DEBUG_LOG("FSM action", "«ancestor::fsm/@filename»_fsm.c, state=«ancestor::state/@name», event=«ancestor::event/@name»", "action=«@name»")
    1.26          indent(0);
    1.27          > status = «@name»(session, state, 
    1.28          choose {
    1.29 @@ -261,6 +264,11 @@
    1.30  
    1.31      template "condition" {
    1.32          | cond_result = «@name»(session`apply "parm", 0`);
    1.33 +        | #ifndef NDEBUG
    1.34 +        | char resstr[11] = {0,};
    1.35 +        | snprintf(resstr,10,"result=%d",cond_result);
    1.36 +        | #endif
    1.37 +        | DEBUG_LOG("FSM condition", "«ancestor::fsm/@filename»_fsm.c, state=«ancestor::state/@name», event=«ancestor::event/@name», condition=«@name»", resstr)
    1.38          | if (cond_result < 0)
    1.39          |> return cond_result;
    1.40          | if (cond_result) {
    1.41 @@ -294,6 +302,7 @@
    1.42              const "nextstateparm", "ancestor::fsm/child::state[@name = $nextstatename]/child::parm";
    1.43              | session->sync_state_payload = «yml:lcase(name($nextstateparm/*))»_dup(«name(parm/*)»);
    1.44          }
    1.45 +        | DEBUG_LOG("FSM transition", "«ancestor::fsm/@filename»_fsm.c, state=«ancestor::state/@name», event=«ancestor::event/@name»", "target=«@target»")
    1.46          | return «@target»;
    1.47      }
    1.48  }
     2.1 --- a/sync/generated/sync_fsm.c	Wed Dec 14 17:27:30 2016 +0100
     2.2 +++ b/sync/generated/sync_fsm.c	Thu Dec 15 15:43:14 2016 +0100
     2.3 @@ -19,15 +19,24 @@
     2.4          case InitState:
     2.5          {
     2.6              *timeout = 0;
     2.7 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=InitState")
     2.8              switch (event) {
     2.9                  case Init:
    2.10                  {
    2.11 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=InitState", "event=Init")
    2.12                      cond_result = storedGroupKeys(session);
    2.13 +                    #ifndef NDEBUG
    2.14 +                    char resstr[11] = {0,};
    2.15 +                    snprintf(resstr,10,"result=%d",cond_result);
    2.16 +                    #endif
    2.17 +                    DEBUG_LOG("FSM condition", "sync_fsm.c, state=InitState, event=Init, condition=storedGroupKeys", resstr)
    2.18                      if (cond_result < 0)
    2.19                          return cond_result;
    2.20                      if (cond_result) {
    2.21 +                        DEBUG_LOG("FSM transition", "sync_fsm.c, state=InitState, event=Init", "target=Grouped")
    2.22                          return Grouped;
    2.23                      }
    2.24 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=InitState, event=Init", "target=Sole")
    2.25                      return Sole;
    2.26                  }
    2.27                  default:
    2.28 @@ -38,10 +47,13 @@
    2.29          case Sole:
    2.30          {
    2.31              *timeout = 0;
    2.32 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=Sole")
    2.33              switch (event) {
    2.34 -                case Init: break;
    2.35 +                case Init: DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=Init") break;
    2.36                  case KeyGen:
    2.37                  {
    2.38 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=KeyGen")
    2.39 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=KeyGen", "action=sendBeacon")
    2.40                      status = sendBeacon(session, state, NULL, NULL);
    2.41                      if (status == PEP_OUT_OF_MEMORY)
    2.42                          return (int) invalid_out_of_memory;
    2.43 @@ -51,6 +63,8 @@
    2.44                  }
    2.45                  case CannotDecrypt:
    2.46                  {
    2.47 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=CannotDecrypt")
    2.48 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=CannotDecrypt", "action=sendBeacon")
    2.49                      status = sendBeacon(session, state, NULL, NULL);
    2.50                      if (status == PEP_OUT_OF_MEMORY)
    2.51                          return (int) invalid_out_of_memory;
    2.52 @@ -60,6 +74,8 @@
    2.53                  }
    2.54                  case Beacon:
    2.55                  {
    2.56 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=Beacon")
    2.57 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=Beacon", "action=sendHandshakeRequest")
    2.58                      status = sendHandshakeRequest(session, state, partner, NULL);
    2.59                      if (status == PEP_OUT_OF_MEMORY)
    2.60                          return (int) invalid_out_of_memory;
    2.61 @@ -69,12 +85,15 @@
    2.62                  }
    2.63                  case HandshakeRequest:
    2.64                  {
    2.65 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Sole", "event=HandshakeRequest")
    2.66 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Sole, event=HandshakeRequest", "action=sendHandshakeRequest")
    2.67                      status = sendHandshakeRequest(session, state, partner, NULL);
    2.68                      if (status == PEP_OUT_OF_MEMORY)
    2.69                          return (int) invalid_out_of_memory;
    2.70                      if (status != PEP_STATUS_OK)
    2.71                          return (int) invalid_action;
    2.72                      session->sync_state_payload = identity_dup(partner);
    2.73 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=Sole, event=HandshakeRequest", "target=HandshakingSole")
    2.74                      return HandshakingSole;
    2.75                  }
    2.76                  default:
    2.77 @@ -86,13 +105,21 @@
    2.78          {
    2.79              Identity expected = (Identity)session->sync_state_payload;
    2.80              *timeout = 600;
    2.81 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=HandshakingSole")
    2.82              switch (event) {
    2.83                  case Init:
    2.84                  {
    2.85 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=Init")
    2.86                      cond_result = keyElectionWon(session, partner);
    2.87 +                    #ifndef NDEBUG
    2.88 +                    char resstr[11] = {0,};
    2.89 +                    snprintf(resstr,10,"result=%d",cond_result);
    2.90 +                    #endif
    2.91 +                    DEBUG_LOG("FSM condition", "sync_fsm.c, state=HandshakingSole, event=Init, condition=keyElectionWon", resstr)
    2.92                      if (cond_result < 0)
    2.93                          return cond_result;
    2.94                      if (cond_result) {
    2.95 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=Init", "action=notifyInitFormGroup")
    2.96                          status = notifyInitFormGroup(session, state, partner, NULL);
    2.97                          if (status == PEP_OUT_OF_MEMORY)
    2.98                              return (int) invalid_out_of_memory;
    2.99 @@ -100,6 +127,7 @@
   2.100                              return (int) invalid_action;
   2.101                      }
   2.102                      else {
   2.103 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=Init", "action=notifyInitAddOurDevice")
   2.104                          status = notifyInitAddOurDevice(session, state, partner, NULL);
   2.105                          if (status == PEP_OUT_OF_MEMORY)
   2.106                              return (int) invalid_out_of_memory;
   2.107 @@ -110,6 +138,8 @@
   2.108                  }
   2.109                  case HandshakeRejected:
   2.110                  {
   2.111 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=HandshakeRejected")
   2.112 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeRejected", "action=rejectHandshake")
   2.113                      status = rejectHandshake(session, state, partner, NULL);
   2.114                      if (status == PEP_OUT_OF_MEMORY)
   2.115                          return (int) invalid_out_of_memory;
   2.116 @@ -119,24 +149,34 @@
   2.117                          free_identity((Identity)session->sync_state_payload);
   2.118                          session->sync_state_payload = NULL;
   2.119                      }
   2.120 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=HandshakeRejected", "target=Sole")
   2.121                      return Sole;
   2.122                  }
   2.123                  case HandshakeAccepted:
   2.124                  {
   2.125 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=HandshakeAccepted")
   2.126 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "action=acceptHandshake")
   2.127                      status = acceptHandshake(session, state, partner, NULL);
   2.128                      if (status == PEP_OUT_OF_MEMORY)
   2.129                          return (int) invalid_out_of_memory;
   2.130                      if (status != PEP_STATUS_OK)
   2.131                          return (int) invalid_action;
   2.132                      cond_result = keyElectionWon(session, partner);
   2.133 +                    #ifndef NDEBUG
   2.134 +                    char resstr[11] = {0,};
   2.135 +                    snprintf(resstr,10,"result=%d",cond_result);
   2.136 +                    #endif
   2.137 +                    DEBUG_LOG("FSM condition", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted, condition=keyElectionWon", resstr)
   2.138                      if (cond_result < 0)
   2.139                          return cond_result;
   2.140                      if (cond_result) {
   2.141 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "action=sendGroupKeys")
   2.142                          status = sendGroupKeys(session, state, partner, NULL);
   2.143                          if (status == PEP_OUT_OF_MEMORY)
   2.144                              return (int) invalid_out_of_memory;
   2.145                          if (status != PEP_STATUS_OK)
   2.146                              return (int) invalid_action;
   2.147 +                        DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "action=notifyAcceptedGroupCreated")
   2.148                          status = notifyAcceptedGroupCreated(session, state, partner, NULL);
   2.149                          if (status == PEP_OUT_OF_MEMORY)
   2.150                              return (int) invalid_out_of_memory;
   2.151 @@ -146,6 +186,7 @@
   2.152                              free_identity((Identity)session->sync_state_payload);
   2.153                              session->sync_state_payload = NULL;
   2.154                          }
   2.155 +                        DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "target=Grouped")
   2.156                          return Grouped;
   2.157                      }
   2.158                      if(session->sync_state_payload){
   2.159 @@ -153,18 +194,23 @@
   2.160                          session->sync_state_payload = NULL;
   2.161                      }
   2.162                      session->sync_state_payload = identity_dup(partner);
   2.163 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=HandshakeAccepted", "target=WaitForGroupKeysSole")
   2.164                      return WaitForGroupKeysSole;
   2.165                  }
   2.166                  case Cancel:
   2.167                  {
   2.168 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=Cancel")
   2.169                      if(session->sync_state_payload){
   2.170                          free_identity((Identity)session->sync_state_payload);
   2.171                          session->sync_state_payload = NULL;
   2.172                      }
   2.173 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=Cancel", "target=Sole")
   2.174                      return Sole;
   2.175                  }
   2.176                  case Timeout:
   2.177                  {
   2.178 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingSole", "event=Timeout")
   2.179 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingSole, event=Timeout", "action=notifyTimeout")
   2.180                      status = notifyTimeout(session, state, expected, NULL);
   2.181                      if (status == PEP_OUT_OF_MEMORY)
   2.182                          return (int) invalid_out_of_memory;
   2.183 @@ -174,6 +220,7 @@
   2.184                          free_identity((Identity)session->sync_state_payload);
   2.185                          session->sync_state_payload = NULL;
   2.186                      }
   2.187 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingSole, event=Timeout", "target=Sole")
   2.188                      return Sole;
   2.189                  }
   2.190                  default:
   2.191 @@ -185,15 +232,19 @@
   2.192          {
   2.193              Identity expected = (Identity)session->sync_state_payload;
   2.194              *timeout = 600;
   2.195 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=WaitForGroupKeysSole")
   2.196              switch (event) {
   2.197 -                case Init: break;
   2.198 +                case Init: DEBUG_LOG("FSM event", "sync_fsm.c, state=WaitForGroupKeysSole", "event=Init") break;
   2.199                  case GroupKeys:
   2.200                  {
   2.201 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=WaitForGroupKeysSole", "event=GroupKeys")
   2.202 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=WaitForGroupKeysSole, event=GroupKeys", "action=storeGroupKeys")
   2.203                      status = storeGroupKeys(session, state, partner, extra /*keys*/);
   2.204                      if (status == PEP_OUT_OF_MEMORY)
   2.205                          return (int) invalid_out_of_memory;
   2.206                      if (status != PEP_STATUS_OK)
   2.207                          return (int) invalid_action;
   2.208 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=WaitForGroupKeysSole, event=GroupKeys", "action=notifyAcceptedDeviceAdded")
   2.209                      status = notifyAcceptedDeviceAdded(session, state, partner, NULL);
   2.210                      if (status == PEP_OUT_OF_MEMORY)
   2.211                          return (int) invalid_out_of_memory;
   2.212 @@ -203,10 +254,13 @@
   2.213                          free_identity((Identity)session->sync_state_payload);
   2.214                          session->sync_state_payload = NULL;
   2.215                      }
   2.216 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=WaitForGroupKeysSole, event=GroupKeys", "target=Grouped")
   2.217                      return Grouped;
   2.218                  }
   2.219                  case Timeout:
   2.220                  {
   2.221 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=WaitForGroupKeysSole", "event=Timeout")
   2.222 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=WaitForGroupKeysSole, event=Timeout", "action=notifyTimeout")
   2.223                      status = notifyTimeout(session, state, expected, NULL);
   2.224                      if (status == PEP_OUT_OF_MEMORY)
   2.225                          return (int) invalid_out_of_memory;
   2.226 @@ -216,6 +270,7 @@
   2.227                          free_identity((Identity)session->sync_state_payload);
   2.228                          session->sync_state_payload = NULL;
   2.229                      }
   2.230 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=WaitForGroupKeysSole, event=Timeout", "target=Sole")
   2.231                      return Sole;
   2.232                  }
   2.233                  default:
   2.234 @@ -226,9 +281,12 @@
   2.235          case Grouped:
   2.236          {
   2.237              *timeout = 0;
   2.238 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=Grouped")
   2.239              switch (event) {
   2.240                  case Init:
   2.241                  {
   2.242 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=Init")
   2.243 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=Init", "action=enterGroup")
   2.244                      status = enterGroup(session, state, NULL, NULL);
   2.245                      if (status == PEP_OUT_OF_MEMORY)
   2.246                          return (int) invalid_out_of_memory;
   2.247 @@ -238,6 +296,8 @@
   2.248                  }
   2.249                  case KeyGen:
   2.250                  {
   2.251 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=KeyGen")
   2.252 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=KeyGen", "action=sendGroupUpdate")
   2.253                      status = sendGroupUpdate(session, state, NULL, NULL);
   2.254                      if (status == PEP_OUT_OF_MEMORY)
   2.255                          return (int) invalid_out_of_memory;
   2.256 @@ -247,6 +307,8 @@
   2.257                  }
   2.258                  case CannotDecrypt:
   2.259                  {
   2.260 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=CannotDecrypt")
   2.261 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=CannotDecrypt", "action=sendUpdateRequest")
   2.262                      status = sendUpdateRequest(session, state, NULL, NULL);
   2.263                      if (status == PEP_OUT_OF_MEMORY)
   2.264                          return (int) invalid_out_of_memory;
   2.265 @@ -256,6 +318,8 @@
   2.266                  }
   2.267                  case UpdateRequest:
   2.268                  {
   2.269 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=UpdateRequest")
   2.270 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=UpdateRequest", "action=sendGroupUpdate")
   2.271                      status = sendGroupUpdate(session, state, NULL, NULL);
   2.272                      if (status == PEP_OUT_OF_MEMORY)
   2.273                          return (int) invalid_out_of_memory;
   2.274 @@ -265,6 +329,8 @@
   2.275                  }
   2.276                  case Beacon:
   2.277                  {
   2.278 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=Beacon")
   2.279 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=Beacon", "action=sendHandshakeRequest")
   2.280                      status = sendHandshakeRequest(session, state, partner, NULL);
   2.281                      if (status == PEP_OUT_OF_MEMORY)
   2.282                          return (int) invalid_out_of_memory;
   2.283 @@ -274,16 +340,21 @@
   2.284                  }
   2.285                  case HandshakeRequest:
   2.286                  {
   2.287 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=HandshakeRequest")
   2.288 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=HandshakeRequest", "action=sendHandshakeRequest")
   2.289                      status = sendHandshakeRequest(session, state, partner, NULL);
   2.290                      if (status == PEP_OUT_OF_MEMORY)
   2.291                          return (int) invalid_out_of_memory;
   2.292                      if (status != PEP_STATUS_OK)
   2.293                          return (int) invalid_action;
   2.294                      session->sync_state_payload = identity_dup(partner);
   2.295 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=Grouped, event=HandshakeRequest", "target=HandshakingGrouped")
   2.296                      return HandshakingGrouped;
   2.297                  }
   2.298                  case GroupUpdate:
   2.299                  {
   2.300 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=Grouped", "event=GroupUpdate")
   2.301 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=Grouped, event=GroupUpdate", "action=storeGroupKeys")
   2.302                      status = storeGroupKeys(session, state, partner, extra /*keys*/);
   2.303                      if (status == PEP_OUT_OF_MEMORY)
   2.304                          return (int) invalid_out_of_memory;
   2.305 @@ -300,9 +371,12 @@
   2.306          {
   2.307              Identity expected = (Identity)session->sync_state_payload;
   2.308              *timeout = 600;
   2.309 +            DEBUG_LOG("Entering FSM state", "sync_fsm.c", "state=HandshakingGrouped")
   2.310              switch (event) {
   2.311                  case Init:
   2.312                  {
   2.313 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=Init")
   2.314 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=Init", "action=notifyInitAddOurDevice")
   2.315                      status = notifyInitAddOurDevice(session, state, partner, NULL);
   2.316                      if (status == PEP_OUT_OF_MEMORY)
   2.317                          return (int) invalid_out_of_memory;
   2.318 @@ -312,6 +386,8 @@
   2.319                  }
   2.320                  case HandshakeRejected:
   2.321                  {
   2.322 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=HandshakeRejected")
   2.323 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeRejected", "action=rejectHandshake")
   2.324                      status = rejectHandshake(session, state, partner, NULL);
   2.325                      if (status == PEP_OUT_OF_MEMORY)
   2.326                          return (int) invalid_out_of_memory;
   2.327 @@ -321,15 +397,19 @@
   2.328                          free_identity((Identity)session->sync_state_payload);
   2.329                          session->sync_state_payload = NULL;
   2.330                      }
   2.331 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeRejected", "target=Grouped")
   2.332                      return Grouped;
   2.333                  }
   2.334                  case HandshakeAccepted:
   2.335                  {
   2.336 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=HandshakeAccepted")
   2.337 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeAccepted", "action=acceptHandshake")
   2.338                      status = acceptHandshake(session, state, partner, NULL);
   2.339                      if (status == PEP_OUT_OF_MEMORY)
   2.340                          return (int) invalid_out_of_memory;
   2.341                      if (status != PEP_STATUS_OK)
   2.342                          return (int) invalid_action;
   2.343 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeAccepted", "action=sendGroupKeys")
   2.344                      status = sendGroupKeys(session, state, partner, NULL);
   2.345                      if (status == PEP_OUT_OF_MEMORY)
   2.346                          return (int) invalid_out_of_memory;
   2.347 @@ -339,10 +419,13 @@
   2.348                          free_identity((Identity)session->sync_state_payload);
   2.349                          session->sync_state_payload = NULL;
   2.350                      }
   2.351 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingGrouped, event=HandshakeAccepted", "target=Grouped")
   2.352                      return Grouped;
   2.353                  }
   2.354                  case Timeout:
   2.355                  {
   2.356 +                    DEBUG_LOG("FSM event", "sync_fsm.c, state=HandshakingGrouped", "event=Timeout")
   2.357 +                    DEBUG_LOG("FSM action", "sync_fsm.c, state=HandshakingGrouped, event=Timeout", "action=notifyTimeout")
   2.358                      status = notifyTimeout(session, state, expected, NULL);
   2.359                      if (status == PEP_OUT_OF_MEMORY)
   2.360                          return (int) invalid_out_of_memory;
   2.361 @@ -352,6 +435,7 @@
   2.362                          free_identity((Identity)session->sync_state_payload);
   2.363                          session->sync_state_payload = NULL;
   2.364                      }
   2.365 +                    DEBUG_LOG("FSM transition", "sync_fsm.c, state=HandshakingGrouped, event=Timeout", "target=Grouped")
   2.366                      return Grouped;
   2.367                  }
   2.368                  default: