0

I have an external message coming in every second.
The message payload is saved in a ClientDataSet and displayed in a dbGrid.
No data base is involved. RAM storage only.
This works fine,
BUT,
I have intermittent problems when the dataset is empty and populated the first time.

The code is as follows:

procedure TCtlCfg_DM_WarningsFaults_frm.DecodeRxFrame(Protocol: TProtocolSelection;
//          PROVA UTAN VAR                            VAR Frame : CAN_Driver.TCAN_Frame);
                                                      Frame : CAN_Driver.TCAN_Frame);
var
  OldRecNo          : integer;
//  OldIxname         : string;
//  bMark       : TBookMark;
  WasFiltered       : Boolean;
  IdBitFields       : TCanId_IdBitFields;
  Msg               : TCan_Msg;
  MsgType           : integer;
  GlobalNode        : TCanId_GlobalNode;
  LocalNode         : TCanId_LocalNode;
  SubNode           : TCanId_SubNode;
  EntryType         : integer;
  SubSystemType     : integer;
  SubSystemDeviceId : integer;
  IsActive          : Boolean;
  IsAcked           : Boolean;

begin
  with cdsWarningsFaults do
    begin
      if not Active then Exit;

      Msg := Frame.Msg;
      IdBitFields := DecodeCanId(Protocol, Frame.ID);
      if IdBitFields.SubNode     <> cSubNode_Self      then Exit; // Ignore non controller/slave messages
      if IdBitFields.AddressMode <> cCanId_AddrMode_CA then Exit;

      MsgType := IdBitFields.MessageType;
      if MsgType <> cMsg_CTL_CA_Broadcast_WarningAndFaultList then Exit;
      if Frame.MsgLength < 5 then Exit;

      GlobalNode  := IdBitFields.GlobalNode;
      LocalNode   := IdBitFields.LocalNode;
      SubNode     := IdBitFields.SubNode;

      // Silent exit if wrong node
      if GlobalNode <> fNodeFilter.GlobalNode then Exit;
      if LocalNode  <> fNodeFilter.LocalNode  then Exit;
      if SubNode    <> fNodeFilter.SubNode    then Exit;

      EntryType         := Msg[1];
      SubSystemType     := Msg[2];
      IsActive          := (Msg[3] = 1);
      SubSystemDeviceId := Msg[4];
      IsAcked           := (Msg[8] = 1);

      DisableControls; // 2007-12-03/AJ Flytta inte scrollbars under uppdatering
      OldRecNo    := RecNo;
  //    OldIxName   := IndexName;  // Save current index
  //    IndexName   := IndexDefs.Items[0].Name;
      WasFiltered := Filtered;  // Save filter status
      Filtered    := False;

      try
        try
          if Findkey([GlobalNode, LocalNode, SubNode, EntryType, SubSystemType, SubSystemDeviceId]) then
            begin // Update record
              Edit;
              FieldByName('fIsActive').AsBoolean  := IsActive;
              FieldByName('fIsAcked').AsBoolean   := IsAcked;
              FieldByName('fTimeout').AsDateTime  := GetDatabaseTimeoutAt;
              Post;
              MainForm.AddToActivityLog('CtlCfg_DM_WF: DecodeRxFrame: Efter Edit.    N=' + IntToStr(GlobalNode) + ' ' +
                                                                                           IntToStr(LocalNode)  + ' ' +
                                                                                           IntToStr(SubNode)    +
                                        '  RecCnt=' + IntToStr(RecordCount) +  ' ET=' + IntToStr(EntryType) + ' SST=' + IntToStr(subSystemType) + ' SSD=' + IntToStr(SubSystemDeviceId), False);
            end
          else
            begin // Create new record
              Append;
              MainForm.AddToActivityLog('CtlCfg_DM_WF: DecodeRxFrame: Efter Append.  N=' + IntToStr(GlobalNode) + ' ' +
                                                                                           IntToStr(LocalNode)  + ' ' +
                                                                                           IntToStr(SubNode)    +
                                        '  RecCnt=' + IntToStr(RecordCount) +  ' ET=' + IntToStr(EntryType) + ' SST=' + IntToStr(subSystemType) + ' SSD=' + IntToStr(SubSystemDeviceId), False);

              try
              FieldByName('fGlobalNode').AsInteger        := GlobalNode;
              FieldByName('fLocalNode').AsInteger         := LocalNode;
              FieldByName('fSubNode').AsInteger           := SubNode;
              FieldByName('fEntryType').AsInteger         := EntryType;
              FieldByName('fSubSystemType').AsInteger     := SubSystemType;
              FieldByName('fSubSystemDeviceId').AsInteger := SubSystemDeviceId;
              FieldByName('fIsActive').AsBoolean          := IsActive;
              FieldByName('fIsAcked').AsBoolean           := IsAcked;
              FieldByName('fTimeout').AsDateTime          := GetDatabaseTimeoutAt;
              finally
                try
                  Post;   // VArför biter inte denna post så att det blir edit nästa gång
                except
                  MainForm.AddToActivityLog('CtlCfg_DM_WF: DecodeRxFrame: Exception efter Post.', True);
                end;
              MainForm.AddToActivityLog('CtlCfg_DM_WF: DecodeRxFrame: Efter Post.    N=' + IntToStr(GlobalNode) + ' ' +
                                                                                           IntToStr(LocalNode)  + ' ' +
                                                                                           IntToStr(SubNode)    +
                                        '  RecCnt=' + IntToStr(RecordCount) +  ' ET=' + IntToStr(EntryType) + ' SST=' + IntToStr(subSystemType) + ' SSD=' + IntToStr(SubSystemDeviceId), False);
              end;
            end;
        except
          on E: Exception do
            begin
              MainForm.AddToActivityLog('Post exception message:      [' + E.Message + ']', False);
              MainForm.AddToActivityLog('Post exception class:        [' + E.ClassName + ']', False);
              MainForm.AddToActivityLog('Post exception Error code:   [' + IntToStr(EDBCLIENT (E).ErrorCode) + ']', False);
              MainForm.AddToActivityLog('Post exception ReadOnly is:  [' + BoolToStr(ReadOnly) + ']', False);
              MainForm.AddToActivityLog('Post exception CanModify is: [' + BoolToStr(CanModify) + ']', False);
              MainForm.AddToActivityLog('DecodeRxFrame: Exception inside FindKey block', False);
              Cancel;
            end;
        end;

      finally
   //     IndexName := OldIxName;   // Restore previous index
        Filtered  := WasFiltered; // Restore filter state
        if (OldRecNo >= 1) and (OldRecNo <= RecordCount) then RecNo := OldRecNo;
        EnableControls;
      end;
    end;

  //MainForm.AddToActivityLog('DecodeRxFrame: Exit ur proceduren', False);
end;

The problem is when the record does not already exist, and I need to Append a new record.
It often works fine, but many times it seems the POST does not work,
and the append is repeated a few or many times when new data comes in.

Suddenly the append works, and subbsequent updates are done using edit,
and as far as I can tell, after that it then works forever.

The issue is intermittent and the number of tries needed to succeed vary.
It feels like a timing issue, but I cannot figure it out.

Any ideas greatly appreciated.
Thanks,
Anders J

AndersJ
  • 411
  • 1
  • 3
  • 15
  • What is "k" and why don't you set the value of the "k" field of cdsXYZ when you do the Append? If you don't, then next time, FindKey will fail again, and again ... PS : indent the code in your q using Ctrl-K. – MartynA Mar 23 '16 at 16:48
  • 'k' is the key/index. I do set the k-field. I left it out for clarity, but have added it now. I'm working on the indentation, I think it is pretty clear now. – AndersJ Mar 23 '16 at 16:54
  • Well, please get in the habit of posting real code, not fake code like "Findkey[k]" which won't even compile - you're asking for free help here, and posting it just wastes readers' time. And show a complete procedure, not just the snippet where you assume the problem arises. – MartynA Mar 23 '16 at 16:59
  • Well, unless anyone can spot anything wrong with that, you may need to post an mcve (http://stackoverflow.com/help/mcve) instead. Preparing one often identifies the problem without needing to post it. Btw, are you sure DecodeRxFrame is never called re-entrantly? – MartynA Mar 23 '16 at 18:21
  • @AndersJ There's nothing clear about "leaving out (variable assignment) for clarity". Erratic bugs often boil down to uninitialised values. – Disillusioned Mar 23 '16 at 23:36
  • You have quite a bit of logging. What does your logging tell you? Unfortunately you have a terrible habit of (a) swallowing and hiding exceptions and (b) ignoring the original exception message. So if you're seeing "Exception efter post" logged, you have no idea what the exception was. – Disillusioned Mar 23 '16 at 23:43
  • Originally I had no logging and no exception handling. Logging was added to help me figure out what is happening, and it tells me that append happens more than once, as if its posts are ignored. Exceptions were added for the same reasons, and tell me nothing, since they never happen. – AndersJ Mar 24 '16 at 03:09
  • @AndersJ Ok. So you say exceptions aren't happening. However, it's still not clear what ***is*** happening. An extract of the logs could help tremendously, because they explain a lot about the flow of the code. I do have some suggestions. I'll give more details in an answer. – Disillusioned Mar 24 '16 at 11:07

1 Answers1

3

As mentioned in my comment a lot can be figured out about how the code flows using an extract of the logs. (Also as a side-note, sometimes you need to be careful of the reliability of your logging system. Your logging is at least partially home-brew, so I have no idea what it means when you arbitrarily pass True/False values to the AddToActivityLog method.)

However, I am still able to offer some guidance to help you identify your problem. I also have some general comments to help you improve your code.

You're not shy to use logging to narrow down your problem: this is a good thing!
However you technique could use a little improvement. You're trying to determine what's going wrong around the Post method. Given such a clear goal, your logging seems surprisingly haphazard.

You should do the following:

//Log the line before Post is called. It confirms when it is called.
//Log important state information to check you're ready to post "correctly"
//In this it's especially useful to know the Sate of the dataset (dsEdit/dsInsert).
Post;
//Log the line after Post to confirm it completed.
//Note that "completed" and "succeeded" aren't always the same, so...
//Again, you want to log important state information (in this case dsBrowse).

If you had this this logging, you might (for example) be able to tell us that:

  • Before calling Post dataset is in dsInsert state.
  • And (assuming no exceptions as you say): after calling Post the dataset is still in dsInsert state.
  • NOTE: If it were in dsBrowse but Post still considered "unsuccessful", you'd be told to log details of the record before and after Post.

So now: Post "completing" without the record being "posted" would give a few more things to look at:

  • What events are hooked to the data set? Especially consider events used for validation.
  • Since you're working with TClientDataSet there's an important event you'll want to take a look at OnPostError. DBClient uses this callback mechanism to notify the client of errors while posting.

If you log OnPostError I'm sure you'll get a better idea of the problem.


Finally I mentioned you have a lot of other problems with your code; especially the error handling.

  • Don't use with until you know how to use it correctly. When you know how to use it correctly, you'll also know there's never a good reason to use it. As it stands, your code is effectively 2 characters short of a subtle bug that could have been a nightmare to even realise it even existed; but would be a complete non-issue without with. (You declared and used a property called IsActive differing by only 2 characters from TDataSet's Active. I'm sure you didn't realise this; and their difference is but an accident. However, if they had been the same, with would very quietly use the wrong one.)

  • You need to write smaller methods - MUCH smaller! Blobs of code like you have are a nightmare to debug and are excellent at hiding bugs.

  • Your exception handling is fundamentally wrong:

Your comment about logging and exception handling suggests that you've been simply adding what you can out of desperation. I think it pays to understand what's going on to keep your logging useful and avoid the clutter. Let's take a close look at the most problematic portion.

/_   try
/_     FieldByName('fGlobalNode').AsInteger        := GlobalNode;
/_E    FieldByName('fLocalNode').AsInteger         := LocalNode;
  |    FieldByName('fSubNode').AsInteger           := SubNode;
  |    FieldByName('fEntryType').AsInteger         := EntryType;
  |    FieldByName('fSubSystemType').AsInteger     := SubSystemType;
  |    FieldByName('fSubSystemDeviceId').AsInteger := SubSystemDeviceId;
  |    FieldByName('fIsActive').AsBoolean          := IsActive;
  |    FieldByName('fIsAcked').AsBoolean           := IsAcked;
  |    FieldByName('fTimeout').AsDateTime          := GetDatabaseTimeoutAt;
  |_ finally
  /_   try
  /_     Post;
  /    except
  |      MainForm.AddToActivityLog(..., True);
  |    end;
  |_   MainForm.AddToActivityLog(..., False);
  /  end;
  |
 ...

So, in the above code:

  • If no exceptions happen, you'd simply step from one line to the next.
  • But as soon as an exception happens, you jump to the next finally/except block.
  • The first problem is: Why would you try to force a Post if you haven't finished setting your field values. It's a recipe for headaches when you end up with records that have only a fraction of the data they should - unless you're lucky and Post fails because critical data is missing.
  • When finally finishes during an exception, code immediately jumps to the next finally/except in the call-stack.
  • Except is slightly different, it only gets called if something did go wrong. (Whereas finally guarantees it will be called with/without an exception.

TIPS: (good for 99% of exception handling cases.

  • Only use try finally for cleanup that must happen in both success and error cases.
  • Nest your try finally blocks: The pattern is <Get Resource>try .... finally<Cleanup>end (The only place to do another resource protection is inside the .....)
  • Avoid except in most cases.
  • The main exception to the previous rule is when cleanup is needed only in the case of an error. In which case: do the cleanup and re-raise the exception.
  • Other than that: only implement an except block without re-raising if you can fully resolve an error condition. (Meaning the lines of code immediately after the exception swallower truly don't care about the previous exception.
Disillusioned
  • 14,635
  • 3
  • 43
  • 77
  • 1
    Craig, thanks for extremely valuable criticism. I will look into all you say. This method has been used before in other similar situations that also involved setting the Filtered property true. In this case filtering is not used, and the filter property is blank. Filtered was however still true. Setting Filtered to false seemed to fix the problem. Is this filter usage a mistake that could create issues? Or do I need to look for a better explanation? I may be wrong, since the problem is intermittent, but I haven't seen it for a couple of hours now. – AndersJ Mar 24 '16 at 13:13
  • 1
    I added a OnPostError event and set Filtered back to True. The OnPost Error triggers, with a blank message, class is EDBCLient and error code is 10756. I investigated a similar issue back in 2012 but was unable to to figure it out. http://codeverge.com/embarcadero.delphi.database/why-does-a-clientdataset-suddenly/1071241 – AndersJ Mar 24 '16 at 13:44