Re: [naviserver-devel] more logging problems on Windows
On Mon, Nov 17, 2014 at 10:36:48AM +0100, Gustaf Neumann wrote: > The problem is not a argument-passing or memory problem, > but seems to be a linking problem. When a file is opened in a > module (here nslog) only this module can write successfully > to this file. Under Windows other dlls can't write to it, even > when they write to the same fd. It seems to me as if the > nslog dll is linked to a private runtime environment. Very interesting! Good detective work, Gustaf. > Andrew, can you compare the linking options for nslog with these > from Maurizio? I don't know what link options Maurizio is using. On Mon, Nov 17, 2014 at 01:05:28PM +0100, Gustaf Neumann wrote: > that's a very good hint: AFIKT, all the modules used already the > same /M* options. However, i've changed the runtime library > option from /MT* to MD* (multi-threaded version) and a quick > test (fildes to windows handle conversion) indicates that > the strange behavior is gone. We've been using /MTd (or plain /MT for non-debug builds) for everything, because that's what was in the include/Makefile.win32 Ibrahim sent me, which was identical to the version in Mercurial last touched by Vlad Seryakov back in 2007. >From Microsoft's docs: http://msdn.microsoft.com/en-us/library/2kzt1wy3%28v=vs.110%29.aspx http://support.microsoft.com/kb/140584/en-us "/MT" is the "multithread, static version" "/MD" is the "multithread- and DLL-specific version" Microsoft warns about mixing two different versions of the run-time library, but says nothing about the mysterious file IO behavior we saw with /MTd. I looked through my three hardcopy books on Windows system programming and found nothing relevant there either. The most useful discussion I found of /MT vs. /MD (although still not at all complete) was here: http://stackoverflow.com/questions/757418/should-i-compile-with-md-or-mt It sounds like /MDd is the right default for Naviserver's Windows builds. I haven't tried that or updated to Gustaf's latest code yet, but will do so soon. I'm compiling and running Naviserver on the same machine anyway, so /MD should be completely fine for my use. From the discussion above, it sounds like someone distributing compiled binaries to run on other machines MIGHT prefer to use /MT to simplify their application install process, but even there /MD is still probably the correct default. -- Andrew Piskorski -- Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server from Actuate! Instantly Supercharge Your Business Reports and Dashboards with Interactivity, Sharing, Native Excel Exports, App Integration & more Get technology previously reserved for billion-dollar corporations, FREE http://pubads.g.doubleclick.net/gampad/clk?id=157005751&iu=/4140/ostg.clktrk ___ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
Hi Ibrahim, that's a very good hint: AFIKT, all the modules used already the same /M* options. However, i've changed the runtime library option from /MT* to MD* (multi-threaded version) and a quick test (fildes to windows handle conversion) indicates that the strange behavior is gone. Nevertheless, using the ns_ prefix for the OS-interface is still beneficial for handling of different prototypes on different operating systems and leads to a better abstraction than the macros, which were a mere measure to reduce windows compiler warning (to use ISO names _open, _close etc.). This small change will certainly help people to keep their hair on their head, when they try to adapt more naviserver modules for windows all the best -g [1] https://bitbucket.org/naviserver/naviserver/commits/08680db31a71a6c8d512a6f7e7de64303c5ac262 On 17.11.14 10:52, Ibrahim Tannir wrote: > Hi Gustaf, > > Just a hint: it is absolutely essential that all the > modules on Windows be compiled with the same model. I use > -MD or -MDd. Otherwise, each of the modules compiled with > a different model will have it's own global variables, > environment and memory segment and the two modules will > not interact even if they share the same global variables. > It goes even further with whether the modules use MFC and > common runtime or not, which Microsoft libraries they will > include. That is why I avoid using make files and let > Visual Studio do all the work and I make sure that all the > modules have the same setup (see attached file). (I have > shared my project files, all of which I created myself, > with someone from the community recently). > > Hope this helps, > Ibrahim > > > > On 17-Nov-14 10:36, Gustaf Neumann wrote: >> Dear Andrew and all, >> >> Over the weekend, I invested some more time into the windows >> port and got a better understanding of the logging issue >> (a write() >> operation succeeds inside nslog.c, but the identically >> operations >> inside driver.c does not work; "not work" means, that the >> write >> operation succeeds (i.e. reports the written number of >> bytes), >> but the file is always empty, even after a close()). >> >> The problem is not a argument-passing or memory problem, >> but seems to be a linking problem. When a file is opened >> in a >> module (here nslog) only this module can write successfully >> to this file. Under Windows other dlls can't write to it, >> even >> when they write to the same fd. It seems to me as if the >> nslog dll is linked to a private runtime environment. >> Looking up the windows handle same file descriptor >> (e.g. 3) leads to a different results when performed in >> nslog.c >> or in driver.c (or somewhere else in a function in libnsd). >> >> The current solution is to define for windows stub-functions >> ns_open, ns_close, ns_write, ns_read which are defined in >> libnsd. >> These functions are called from ns_log instead of the native >> OS functions (under windows _open, _close, _write, _read), >> which have btw different prototypes, so this abstraction >> seems beneficial for several reasons. >> >> The essential change is in [1], which add the ns_* >> functions and >> reverts the previous _MSV_VER bypass in nslog.c. For >> completeness, ns_tell should be added as well. >> >> Andrew, can you compare the linking options for nslog >> with these >> from Maurizio? Although the problem for nslog seems to be >> solved, >> i would not be surprised if other weirdnesses lurch around >> from other modules. >> >> -g > -- Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server from Actuate! Instantly Supercharge Your Business Reports and Dashboards with Interactivity, Sharing, Native Excel Exports, App Integration & more Get technology previously reserved for billion-dollar corporations, FREE http://pubads.g.doubleclick.net/gampad/clk?id=157005751&iu=/4140/ostg.clktrk ___ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
Hi Gustaf, Just a hint: it is absolutely essential that all the modules on Windows be compiled with the same model. I use -MD or -MDd. Otherwise, each of the modules compiled with a different model will have it's own global variables, environment and memory segment and the two modules will not interact even if they share the same global variables. It goes even further with whether the modules use MFC and common runtime or not, which Microsoft libraries they will include. That is why I avoid using make files and let Visual Studio do all the work and I make sure that all the modules have the same setup (see attached file). (I have shared my project files, all of which I created myself, with someone from the community recently). Hope this helps, Ibrahim On 17-Nov-14 10:36, Gustaf Neumann wrote: Dear Andrew and all, Over the weekend, I invested some more time into the windows port and got a better understanding of the logging issue (a write() operation succeeds inside nslog.c, but the identically operations inside driver.c does not work; "not work" means, that the write operation succeeds (i.e. reports the written number of bytes), but the file is always empty, even after a close()). The problem is not a argument-passing or memory problem, but seems to be a linking problem. When a file is opened in a module (here nslog) only this module can write successfully to this file. Under Windows other dlls can't write to it, even when they write to the same fd. It seems to me as if the nslog dll is linked to a private runtime environment. Looking up the windows handle same file descriptor (e.g. 3) leads to a different results when performed in nslog.c or in driver.c (or somewhere else in a function in libnsd). The current solution is to define for windows stub-functions ns_open, ns_close, ns_write, ns_read which are defined in libnsd. These functions are called from ns_log instead of the native OS functions (under windows _open, _close, _write, _read), which have btw different prototypes, so this abstraction seems beneficial for several reasons. The essential change is in [1], which add the ns_* functions and reverts the previous _MSV_VER bypass in nslog.c. For completeness, ns_tell should be added as well. Andrew, can you compare the linking options for nslog with these from Maurizio? Although the problem for nslog seems to be solved, i would not be surprised if other weirdnesses lurch around from other modules. -g -- Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server from Actuate! Instantly Supercharge Your Business Reports and Dashboards with Interactivity, Sharing, Native Excel Exports, App Integration & more Get technology previously reserved for billion-dollar corporations, FREE http://pubads.g.doubleclick.net/gampad/clk?id=157005751&iu=/4140/ostg.clktrk___ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
Dear Andrew and all, Over the weekend, I invested some more time into the windows port and got a better understanding of the logging issue (a write() operation succeeds inside nslog.c, but the identically operations inside driver.c does not work; "not work" means, that the write operation succeeds (i.e. reports the written number of bytes), but the file is always empty, even after a close()). The problem is not a argument-passing or memory problem, but seems to be a linking problem. When a file is opened in a module (here nslog) only this module can write successfully to this file. Under Windows other dlls can't write to it, even when they write to the same fd. It seems to me as if the nslog dll is linked to a private runtime environment. Looking up the windows handle same file descriptor (e.g. 3) leads to a different results when performed in nslog.c or in driver.c (or somewhere else in a function in libnsd). The current solution is to define for windows stub-functions ns_open, ns_close, ns_write, ns_read which are defined in libnsd. These functions are called from ns_log instead of the native OS functions (under windows _open, _close, _write, _read), which have btw different prototypes, so this abstraction seems beneficial for several reasons. The essential change is in [1], which add the ns_* functions and reverts the previous _MSV_VER bypass in nslog.c. For completeness, ns_tell should be added as well. Andrew, can you compare the linking options for nslog with these from Maurizio? Although the problem for nslog seems to be solved, i would not be surprised if other weirdnesses lurch around from other modules. -g [1] https://bitbucket.org/naviserver/naviserver/commits/70437a26eef9f5f8c801bd813434b50f761e0d4e Am 07.11.14 14:00, schrieb Andrew Piskorski: > On Thu, Nov 06, 2014 at 03:03:18PM +0100, Gustaf Neumann wrote: >> The seemingly same write() operation, which refuses to write to >> the access.log in driver.c works fine when called directly >> in nslog.c. >> > Wow, weird. I tried turning your new fix on/off, and confirm the > behavior you see. -- Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server from Actuate! Instantly Supercharge Your Business Reports and Dashboards with Interactivity, Sharing, Native Excel Exports, App Integration & more Get technology previously reserved for billion-dollar corporations, FREE http://pubads.g.doubleclick.net/gampad/clk?id=157005751&iu=/4140/ostg.clktrk ___ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
Dear Andrew,
I would like to draw your attention to the availability of Visual
Studio 2013 Community Edition.
http://msdn.microsoft.com/en-us/visual-studio-community-vs.aspx
Hope it helps,
Maurizio
-Original Message-
From: Andrew Piskorski [mailto:a...@piskorski.com]
Sent: 07 November 2014 14:00
To: naviserver-devel@lists.sourceforge.net
Subject: Re: [naviserver-devel] more logging problems on Windows
On Thu, Nov 06, 2014 at 03:03:18PM +0100, Gustaf Neumann wrote:
> The seemingly same write() operation, which refuses to write to the
> access.log in driver.c works fine when called directly in nslog.c.
> https://bitbucket.org/naviserver/naviserver/commits/4cb76f20a8464fde98
> ac3147c6184a90442a2808
Wow, weird. I tried turning your new fix on/off, and confirm the behavior
you see. Yet as you said, the new code you added to
NsAsyncWrite() is the same as the old/normal code in NsAsyncWrite()!
So what could the difference possibly be? Since we're not actually using
the async writer thread feature at all, it's even the same thread calling
_write() in both cases. LogTrace() is in nslog.dll while NsAsyncWrite() is
in libnsd.dll, but I don't see how/why that could possibly matter.
Microsoft's docs for _write() and _open() don't mention anything
suspicious:
http://msdn.microsoft.com/en-us/library/1570wh78%28v=vs.100%29.aspx
http://msdn.microsoft.com/en-us/library/z0kc8e3z%28v=vs.100%29.aspx
WinDbg thinks the source file used for Microsoft's _write() was:
"f:\dd\vctools\crt_bld\self_x86\crt\src\write.c"
Naturally I don't have that exact path, but I do have this, which seems to
be the same thing:
"c:\Program Files (x86)\Microsoft Visual Studio 12.0\VC\crt\src\write.c"
For binary files, _write() is a reasonably simple wrapper around
WriteFile(), but it's surprisingly complicated for text-mode files.
My access log seems to always be file descriptor 3, so in WinDbg I set a
breakpoint like this:
bu NsAsyncWrite ".if (fd >= 0n3) {} .else {gc}"
Naviserver opens its access log in text mode; that's the default, and by
stepping through in WinDbg I do see it enter some of the text-mode sections
in _write_nolock().
As a little experiment, in LogOpen() I added a _O_BINARY flag, so it opened
the access log like this:
fd = open(logPtr->file, O_APPEND|O_WRONLY|O_CREAT|_O_BINARY, 0644);
That made no difference to the behavior. (I did NOT run that under WinDbg
to confirm, but presumably it was in binary mode like I asked.) So this lost
writes bug doesn't seem to depend on text vs. binary mode, it's the same for
both.
So, I have no idea. The only ways I can imagine to try further to track
this down would be:
1. See if the bug is replicable in a standalone, non-Naviserver C program.
Maybe with two different DLLs involved.
2. Or, in NsAsyncWrite, do not use _write(), instead call WriteFile()
directly and see what happens.
That sounds like a lot of work though, much more than this really warrants.
I'm really glad you found a work-around, Gustaf! I suggest we just leave it
as is, but add some comments about why it's there.
--
Andrew Piskorski
--
___
naviserver-devel mailing list
naviserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/naviserver-devel
--
Comprehensive Server Monitoring with Site24x7.
Monitor 10 servers for $9/Month.
Get alerted through email, SMS, voice calls or mobile push notifications.
Take corrective actions from your mobile device.
http://pubads.g.doubleclick.net/gampad/clk?id=154624111&iu=/4140/ostg.clktrk
___
naviserver-devel mailing list
naviserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
On Thu, Nov 06, 2014 at 03:03:18PM +0100, Gustaf Neumann wrote:
> The seemingly same write() operation, which refuses to write to
> the access.log in driver.c works fine when called directly
> in nslog.c.
> https://bitbucket.org/naviserver/naviserver/commits/4cb76f20a8464fde98ac3147c6184a90442a2808
Wow, weird. I tried turning your new fix on/off, and confirm the
behavior you see. Yet as you said, the new code you added to
NsAsyncWrite() is the same as the old/normal code in NsAsyncWrite()!
So what could the difference possibly be? Since we're not actually
using the async writer thread feature at all, it's even the same
thread calling _write() in both cases. LogTrace() is in nslog.dll
while NsAsyncWrite() is in libnsd.dll, but I don't see how/why that
could possibly matter.
Microsoft's docs for _write() and _open() don't mention anything
suspicious:
http://msdn.microsoft.com/en-us/library/1570wh78%28v=vs.100%29.aspx
http://msdn.microsoft.com/en-us/library/z0kc8e3z%28v=vs.100%29.aspx
WinDbg thinks the source file used for Microsoft's _write() was:
"f:\dd\vctools\crt_bld\self_x86\crt\src\write.c"
Naturally I don't have that exact path, but I do have this, which
seems to be the same thing:
"c:\Program Files (x86)\Microsoft Visual Studio 12.0\VC\crt\src\write.c"
For binary files, _write() is a reasonably simple wrapper around
WriteFile(), but it's surprisingly complicated for text-mode files.
My access log seems to always be file descriptor 3, so in WinDbg I set
a breakpoint like this:
bu NsAsyncWrite ".if (fd >= 0n3) {} .else {gc}"
Naviserver opens its access log in text mode; that's the default, and
by stepping through in WinDbg I do see it enter some of the text-mode
sections in _write_nolock().
As a little experiment, in LogOpen() I added a _O_BINARY flag, so it
opened the access log like this:
fd = open(logPtr->file, O_APPEND|O_WRONLY|O_CREAT|_O_BINARY, 0644);
That made no difference to the behavior. (I did NOT run that under
WinDbg to confirm, but presumably it was in binary mode like I asked.)
So this lost writes bug doesn't seem to depend on text vs. binary
mode, it's the same for both.
So, I have no idea. The only ways I can imagine to try further to
track this down would be:
1. See if the bug is replicable in a standalone, non-Naviserver C
program. Maybe with two different DLLs involved.
2. Or, in NsAsyncWrite, do not use _write(), instead call WriteFile()
directly and see what happens.
That sounds like a lot of work though, much more than this really
warrants. I'm really glad you found a work-around, Gustaf! I suggest
we just leave it as is, but add some comments about why it's there.
--
Andrew Piskorski
--
___
naviserver-devel mailing list
naviserver-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
Dear Andrew, i've looked a little into "problem one", which looks very weird to me. The seemingly same write() operation, which refuses to write to the access.log in driver.c works fine when called directly in nslog.c. My first suspicion was that write() does not work with size_t in Windows (the msdn pages say the the length argument is "unsigned int", while in the unix world specifies it as size_t), but strange enough, the write operation in driver.c still returns the right number of bytes written. However, a tell(fd) before and after the write() operation reveals, that the write cursor is not moved. It seems to me that size_t is unsigned 32 bit on win32 and win64 anyhow. The change [1] fixes access.log writing for the time being, but it will ignore async writing even if configured, but that's just an optional feature for high traffic web-sites with much disk I/O. You are much more experienced with windows development than i am, so maybe you can find the real cause. -g [1] https://bitbucket.org/naviserver/naviserver/commits/4cb76f20a8464fde98ac3147c6184a90442a2808 On 03.11.14 04:27, Andrew Piskorski wrote: > On Windows, I see two additional problems with logging: > > One, the access log file is opened and seems to get rolled/renamed > properly, but it is always empty, zero bytes! No content ever seems > to make it into the access log file. > -- ___ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel
Re: [naviserver-devel] more logging problems on Windows
On Sun, Nov 02, 2014 at 10:27:21PM -0500, Andrew Piskorski wrote: > Two, calling ns_logroll crashed Naviserver with this error: > > Debug Assertion Failed! > f:\dd\vctools\crt_bld\self_x86\crt\src\write.c > Line: 68 > Expression: (_osfile(fh) & FOPEN) Once the nsd debug symbols were working, that one turned out to be an easy fix. All it took was moving the call to Ns_Log() AFTER LogOpen() rather than before it. Done here: https://bitbucket.org/apiskors/naviserver/commits/8d3c79974f084d074f44a9169be75bfa2c5f86bd -- Andrew Piskorski -- ___ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel
