Hello,

I'm trying to debug a strange thing I saw in production (the main symptom, but not the only one, is a TSynEdit in a tab in a TPageControl that goes completely blank, no text, no scrollbars, no nothing, I suspect I'm clobbering some memory but I'm not sure). So I setup a windows 7 virtual machine in a server to leave my program running under the debugger until it "breaks".
I was accessing the server though rdp and, as soon as I close the session, the program gives the "Invalid format string" exception in DateTimeToStr, if I click "continue" the exception is triggered again in the next call, and again, and again.

Now I'm using vnc to access the server, but I'm wondering what could be causing that exception. Could be windows broadcasting a message when the rdp session terminates, a message that TApplication mishandles?

Bye

El 24/01/17 a les 17:50, Luca Olivetti via Lazarus ha escrit:

Forgot to say, lazarus 1.6.2, fpc 2.6.4, win32

Bye

Please provide a stacktrace.

[...] Forgot to say, lazarus 1.6.2, fpc 2.6.4, win32

Good to know.

Mattias

El 24/01/17 a les 19:05, Mattias Gaertner via Lazarus ha escrit:

I didn't manage to provoke (yet) the symptoms as above, but this is the call stack when I connect (or disconnect) via rdp

#0 fpc_raiseexception at :0
#1
SYSUTILS_DATETIMETOSTRING$crc782201FE_STOREFORMAT$ANSISTRING$LONGINT$BOOLEAN at :0
#2
SYSUTILS_DATETIMETOSTRING$crc782201FE_STOREFORMAT$ANSISTRING$LONGINT$BOOLEAN at :0
#3
SYSUTILS_DATETIMETOSTRING$ANSISTRING$ANSISTRING$TDATETIME$TFORMATSETTINGS at :0
#4 SYSUTILS_DATETIMETOSTRING$ANSISTRING$ANSISTRING$TDATETIME at :0 #5 SYSUTILS_DATETIMETOSTR$TDATETIME$$ANSISTRING at :0 #6 TLOGGER__INTERNALLOG(0x1eab2390 '127.0.0.1:57233 Nueva conexi'#195#179'n desde 127.0.0.1:57233', <error reading variable>) at D:\boda_t10_l1_pc\comun\utils.pas:149
#7 TLOGGER__LOG(0x1eab2390 '127.0.0.1:57233 Nueva conexi'#195#179'n desde 127.0.0.1:57233', <error reading variable>) at D:\boda_t10_l1_pc\comun\utils.pas:190
#8 TMAINFRM__FTPLOG(0x1eab2390 '127.0.0.1:57233 Nueva conexi'#195#179'n desde 127.0.0.1:57233', <error reading variable>) at main.pas:352 #9 TFTPKESERVER__SYNCLOG(<error reading variable>) at D:\boda_t10_l1_pc\comun\ftpkeserver.pas:458
#10 CLASSES_CHECKSYNCHRONIZE$LONGINT$$BOOLEAN at :0 #11 TWINDOWPROCHELPER__DOWINDOWPROC(<error reading variable>) at .\win32\win32callback.inc:1960
#12 WINDOWPROC(787992, 0, 0, 0) at .\win32\win32callback.inc:2601 #13 USER32!IsWindowVisible at :0
#14 ?? at :0
#15 USER32!IsWindowVisible at :0
#16 TWINDOWPROCHELPER__DOWINDOWPROC(<error reading variable>) at .\win32\win32callback.inc:2571
#17 USER32!IsWindowVisible at :0
#18 ?? at :0

Line 1960 of win32callback.inc is the CheckSynchronize in

   case Msg of
     WM_NULL:
       if (Window = Win32WidgetSet.AppHandle) then
       begin
         CheckSynchronize;
         TWin32Widgetset(Widgetset).CheckPipeEvents;
       end;

(of TWindowProcHelper.DoWindowProc)

El 24/01/17 a les 19:24, Luca Olivetti via Lazarus ha escrit:

Btw, if I then "reset the debugger" and try to start the program again, I get a lazarus exception "illegal character in format string". If I click Ok (ignore), the program doesn't run and the same message appears again when I press play another time, if I click cancel (kill lazarus), then I get a "read error, access violation, access violation" dialog box. I saw this from time to time since I switched to lazarus 1.6.2 but I didn't worry too much about it.

Start searching for the bug in TLOGGER.LOG.

Mattias

El 24/01/17 a les 22:34, Mattias Gaertner via Lazarus ha escrit:

I don't see it (FMemo is a TSynEdit, anyway it bombs in the call to DateTimeToStr). Besides, I don't see the relation with opening or closing an RDP connection to the virtual machine (there should be plenty of calls to CheckSynchronize at any other time and they don't trigger this bug)

procedure TLogger.Log(const m: string);
begin
   if m=FLastMsg then
   begin
     Repeated(false);
   end else
   begin
     Repeated(true);
     FLastMsg:=m;
     InternalLog(m); <---took this branch
   end;
end;
procedure TLogger.InternalLog(const m: string);
var final:boolean;
begin
   //check if at the end of the log
   final:=FMemo.topline>FMemo.Lines.Count-FMemo.LinesInWindow;
   FMemo.lines.BeginUpdate;
   if FMemo.lines.count>5000 then
     FMemo.lines.delete(0);
   Fmemo.lines.add(DateTimeToStr(now)+' '+m); <---exception triggered here
   FMemo.lines.EndUpdate;
   //if we wer at the end scroll to keep the new line visible
   if final then
     FMemo.TopLine:=FMemo.Lines.Count-FMemo.LinesInWindow+1;
   FLogFile.Log(m);
end;
procedure TLogger.Repeated(clear:boolean);
begin
   if not clear then
     FLastMsgCount:=FLastMsgCount+1;
   if (clear and (FLastMsgCount>0)) or (not clear and (FLastMsgCount mod
100 = 0))  then
     InternalLog(format('last message repeated %d times', [FLastMsgCount]));
   if clear then
     FLastMsgCount:=0;
end;

Bye

El 24/01/17 a les 22:34, Mattias Gaertner via Lazarus ha escrit:

Armed with a debug version of the rtl I get a different error (sigsev) and a different stack trace:

#0 ResumeThread at :0
#1 WideCharToMultiByte at :0
#2 WIN32UNICODE2ANSIMOVE(0x1a5f794 'ene', 0xfe97bd8 'ene', 65001) at D:\fpc-2.6.4\rtl\win\syswin.inc:547
#3 GETLOCALESTR(3082, 68, 0x1f69e0 'ene', 0xfe97bd8 'ene') at winlazutf8.inc:361
#4 GETLOCALEFORMATSETTINGSUTF8(3082, {CURRENCYFORMAT = 3, NEGCURRFORMAT = 8, THOUSANDSEPARATOR = 46 '.', DECIMALSEPARATOR = 44 ',', CURRENCYDECIMALS = 2, DATESEPARATOR = 47 '/', TIMESEPARATOR = 58 ':', LISTSEPARATOR = 59 ';', CURRENCYSTRING = 0x1f6b10 #128, SHORTDATEFORMAT = 0x1feca8 'dd/MM/yyyy', LONGDATEFORMAT = 0x1eea18 'dddd, dd'' de ''MMMM'' de ''yyyy', TIMEAMSTRING = 0x0, TIMEPMSTRING = 0x0, SHORTTIMEFORMAT = 0x1fecc8 'h:nn', LONGTIMEFORMAT = 0x1fece8 'h:nn:ss', SHORTMONTHNAMES = {0x1f69e0 'ene', 0x1f69f0 'feb', 0x1f6a00 'mar', 0x1f6a10 'abr', 0x1f6a20 'may', 0x1f6a30 'jun', 0x1f6a40 'jul', 0x1f6a50 'ago', 0x1f6a60 'sep', 0x1f6a70 'oct', 0x1f6a80 'nov', 0x1f6a90 'dic'}, LONGMONTHNAMES = {0x1fea48 'enero', 0x1fea68 'febrero', 0x1fea88 'marzo', 0x1feaa8 'abril', 0x1feac8 'mayo', 0x1feae8 'junio', 0x1feb08 'julio', 0x1feb28 'agosto', 0x1feb48 'septiembre', 0x1feb68 'octubre', 0x1feb88 'noviembre', 0x1feba8 'diciembre'}, SHORTDAYNAMES = {0x1f6aa0 'dom', 0x1f6ab0 'lun', 0x1f6ac0 'mar', 0x1f6ad0 'mi'#233, 0x1f6ae0 'jue', 0x1f6af0 'vie', 0x1f6b00 's'#225'b'}, LONGDAYNAMES = {0x1febc8 'domingo', 0x1febe8 'lunes', 0x1fec08 'martes', 0x1fec28 'mi'#233'rcoles', 0x1fec48 'jueves', 0x1fec68 'viernes', 0x1fec88 's'#225'bado'}, TWODIGITYEARCENTURYWINDOW = 50}) at winlazutf8.inc:436 #5 :474
#6 TAPPLICATION__INTFSETTINGSCHANGE(<error reading variable>) at .\include\application.inc:1997
#7 TWINDOWPROCHELPER__DOWINDOWPROC(<error reading variable>) at .\win32\win32callback.inc:2307
#8 WINDOWPROC(155124590, 26, 24, 27655548) at .\win32\win32callback.inc:2601 #9 CUSTOMFORMWNDPROC(155124590, 26, 24, 27655548) at .\win32\win32wsforms.pp:382
#10 USER32!IsWindowVisible at :0
#11 ?? at :0
#12 ?? at :0
#13 ?? at :0
#14 ?? at :0
#15 USER32!SetThreadDesktop at :0
#16 USER32!GetSystemMenu at :0
#17 ?? at :0

Now, #3 is this function in winlazutf8.inc

function GetLocaleStr(aLocaleID, aLCType: Longint; const Def: string):
String;
var
   L: Integer;
   Buf: array[0..255] of WideChar;
begin
   L := GetLocaleInfoW(aLocaleID, aLCType, Buf, SizeOf(Buf));
   if L > 0 then
   begin
     Result:='';
     {$IF FPC_FULLVERSION >= 30000}
widestringmanager.Wide2AnsiMoveProc(PWideChar(@Buf[0]),Result,CP_UTF8,L-1);
     {$ELSE}
     widestringmanager.Wide2AnsiMoveProc(PWideChar(@Buf[0]),Result,CP_UTF8);
     {$ENDIF}
   end
   else
     Result := Def;
end;

and since this is fpc2.6.4 the call is the second one:

widestringmanager.Wide2AnsiMoveProc(PWideChar(@Buf[0]),Result,CP_UTF8);

which jumps at #2 to

procedure Win32Unicode2AnsiMove(source:punicodechar;var
dest:ansistring;len:SizeInt);

Uh? The third parameter is supposed to be the length, not the codepage.

If I change that to

widestringmanager.Wide2AnsiMoveProc(PWideChar(@Buf[0]),Result,L-1)

the error disappears.
Reported as http://bugs.freepascal.org/view.php?id=31272

Now, back to my original problem....(TPageControl components randomly disappearing)

Bye

El 25/01/17 a les 09:06, Luca Olivetti via Lazarus ha escrit:

Or maybe this is it: if the production system triggers an WM_SETTINGCHANGE message it could be overwriting some memory pertaining to that TPageControl (long shot, I know, but...)

Bye

El 25/01/17 a les 09:09, Luca Olivetti via Lazarus ha escrit:

Another question is, shouldn't GetFormatSettingsUTF8 get called at application startup and not only in case of an WM_SETTINGCHANGE message?

Bye

El 25/01/17 a les 09:23, Luca Olivetti via Lazarus ha escrit:

Added a note to the bug report: my patch fixes the sigsev but the returned strings are *not* in utf8.

Bye