Hi all,
Looking for some advice/strategies for troubleshooting in real time when my WWC app is hanging. Here's some background.
I'm running 4 instances in COM mode on a single IIS server. WW logging is in SQL Server. I'm also running Web Monitor which helps me know when the application is in a bad state (and which I'm sure there are better ways to configure but that's another topic). Request timeout is set to 300 seconds. On rare occasions, I find that all 4 instances are handling seemingly long running requests which then results in the application refusing additional connections (of course). What I'm trying to figure out is how to see in real-time what the current long running requests are.
- My first working assumption is that the wwrequestlog record is only written after the request completes. Is this correct?
- If the request times out, does a wwrequestlog record still get written? If so, is there a simple way to identify those records?
- What is the best way to correlate a wwsession record to corresponding wwrequest log record(s)?
- Are there any recommended customizations to wwrequest/wwsession logging that folks are using?
Thoughts/comments/suggestions appreciated.
TIA
Yeah request logging only occurs post request. This is mainly done for performance as that would require multiple hits in the database - one with a search that is unoptimized because there's no index on the file and it can get very large. So - no logging for the failure requests.
However, the Web Connection Connector log (temp/wcerror.txt) can be set up for detail logging, which will write out request start and end information so that will show the active/hung requests. But you can only look at that in real time on the server because it's not in a Web accessible path (it's in the configured temp folder).
If requests fail due to timeout, Web Connection servers are shut down, so the errors don't show up in the request log, but they do show up in the Connector logs in wcerror.txt.
+++ Rick ---
Thanks, Rick. Would that be the
LogDetail=1
flag? Is that something I set in web.config? What are the implications of leaving this on?
If you're on a recent version of Web Connection you can do it from the admin page:
This setting controls LogDetail=true in web.config.
Detail logging is very verbose - it logs every request start and stop, any failures and a bunch of other stuff so those logs get large. On a busy site the file locks on that file can also cause brief request delays as synchronization between multi-instances fight over the file lock. It's a debugging tool - you don't want to use it on a regular basis in production.
+++ Rick ---
Found it, thanks.
Bit of a catch-22 here as I want to catch this in the act...
Bit of a catch-22 here as I want to catch this in the act...
Sure, but run it only as long as you need to see it happen.
For most sites the perf impact isn't a problem, but keep an eye on the log size. It sucks having GB's of log data to open in an editor 😄
+++ Rick ---
Thanks. I didn't just want to turn it on and leave it on if it was going to make things worse. Coincidentally, I had an event this morning. Here's what I found in wcerrors.txt (standard logging):
2021-09-22 05:16:23.502 - 4283478833653376_158 - Com Server request timeout. Forcing server to reload - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:23.502 - 4283478833653376_158 - Com Server Execution Error: The remote procedure call failed. (Exception from HRESULT: 0x800706BE) - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:33.402 - 4293396839853377_183 - Com Server request timeout. Forcing server to reload - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:33.402 - 4293396839853377_183 - Com Server Execution Error: The remote procedure call failed. (Exception from HRESULT: 0x800706BE) - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:38.149 - 4298131221153380_25 - Com Server request timeout. Forcing server to reload - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:38.149 - 4298131221153380_25 - Com Server Execution Error: The remote procedure call failed. (Exception from HRESULT: 0x800706BE) - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:45.270 - 4305251389853382_32 - Com Server request timeout. Forcing server to reload - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
2021-09-22 05:16:45.270 - 4305251389853382_32 - Com Server Execution Error: The remote procedure call failed. (Exception from HRESULT: 0x800706BE) - /cnsgbllg.r3?cm=settemail&sn=SM2017+&rl=RCPT_65G0B4DG5.dbf&ob=rcptasce&hc=N&ms=&pl=&up=&cs=&cd=&sf=&fs=filtAll&pt=
I guess I'll enable detailed logging and just set a daily reminder to check that the file isn't getting out of hand.
Completely unrelated side note; when using the dialog here to put in a code snippet, it will not close without picking a syntax type but the UI does not indicate syntax choice is required. As Whil Hentzen might have said circa 1999, that's a bit of a user-hostile interface... 😃
it will not close without picking a syntax type
Sure it will. It'll throw up a confirm dialog and if you cancel it'll just exit.
+++ Rick ---