WebTier into Access Violation
Ok, some strange effects and just at once, normally nothing changed to the
system as i even was on holiday.
Did some testing.
With a normal report explorer from a delphi exe everythign worked fine.
Using the same DLL on my local dev machine, pointing to the same server,
working fine.
Copying this dll to the production machine resulst into this access
violation.
In the chache everything is created except the 0001.htm (the first page) ...
Any suggestions .....
-->",weResponse,1,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:15:30:828","Session
UnLocked",weSessionUnlocked,1,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:15:30:828","Garbage Collection in Separate Thread",weGarbage,0,
"20050414
09:15:58:281",content=viewer_volume=Archived_Reports_name=Ticket_Sales\Feature_Reports\Features_By_Performance\Kinepolis_'Gent\_2005\Month_02'_folder=v0d0d2d0d1d1_SessionID={94E53B8D-F20E-4ADB-8C60-653855B1568B}_zoom=100,weRequest,2,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
050414 09:15:58:281","Session
Locked",weSessionLocked,2,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:16:07:546","TrsWebReportGenerator.GetClientReport:
BI",weOther,0,
"20050414 09:16:07:562","Session
UnLocked",weSessionUnlocked,2,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:02:51:625","Access violation at address 01A437E1 in module
'SDW_RbWebTier_Tree.dll'. Read of address
00000000",weException,2,{2E1EA621-0575-42BD-8546-DFC32184485D}
system as i even was on holiday.
Did some testing.
With a normal report explorer from a delphi exe everythign worked fine.
Using the same DLL on my local dev machine, pointing to the same server,
working fine.
Copying this dll to the production machine resulst into this access
violation.
In the chache everything is created except the 0001.htm (the first page) ...
Any suggestions .....
-->",weResponse,1,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:15:30:828","Session
UnLocked",weSessionUnlocked,1,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:15:30:828","Garbage Collection in Separate Thread",weGarbage,0,
"20050414
09:15:58:281",content=viewer_volume=Archived_Reports_name=Ticket_Sales\Feature_Reports\Features_By_Performance\Kinepolis_'Gent\_2005\Month_02'_folder=v0d0d2d0d1d1_SessionID={94E53B8D-F20E-4ADB-8C60-653855B1568B}_zoom=100,weRequest,2,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
050414 09:15:58:281","Session
Locked",weSessionLocked,2,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:16:07:546","TrsWebReportGenerator.GetClientReport:
BI",weOther,0,
"20050414 09:16:07:562","Session
UnLocked",weSessionUnlocked,2,{94E53B8D-F20E-4ADB-8C60-653855B1568B}
"20050414 09:02:51:625","Access violation at address 01A437E1 in module
'SDW_RbWebTier_Tree.dll'. Read of address
00000000",weException,2,{2E1EA621-0575-42BD-8546-DFC32184485D}
This discussion has been closed.
Comments
This problem is killing us, we have over 200 users not able to run reports
(we don't have a 'spare' machine to run this high volume).
The report explorer is working fine, eve just showing some archived reports
that are presented over the report server are failing ....
Sorry, I really have no clue...
Obviously something changed. Could be the executing environment of the
machine changed, could be the database being used changed.
First thing to try is to reboot the machine (you probably already tried that
though).
Try creating a blank report that contains no data or report elements. See
whether that can execute on the webtier.
Check anything you can think of for changes....
1. System Software
Perhaps some OS or Virus or Firewall patches were applied, perhaps by
automated download. Perhaps IIS changed or some web applications were
introduced.
2. Other Applications
Perhaps some other applications were installed or were started/stopped on
the machine.
3. Security Settings
Any changes? System or database etc.
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
But the strange thing is the access violation to the address 0000000, wich
mostly happens when pointing/using to a nil pointer.
This is the first time in my life i realy wanted the source code of the app,
in order to debug, although mostly this is to hard to dive into.
I'm installing a smaller second 2003 server to test what could be happening.
I don't think its the database, because even viewing RAF files generates an
error.
I've verified security, given access to everyone full control, still
problems.
Its strange to me thar the session gets a directory, the report a number,
the subdirectory reports is created with 2 files, but when the real htm file
has to be written ......
seeing where in the code the error might happen so that you could give me a
hint ???
I'm running the webtier on a temporary server, and i'm back operational.
Now i have time to look in depth what is happening.
The Normal Server is a 4processor machine with 8G internal memory.
Even at moment the processor usage is at 1% it takes up to 10 seconds ro
execute the
rsWebTier.SessionExists(aWebrequest), even webtier and server run ning on
the same machine.
The sidekick-webtier takes up to 5 mili-seconds for this !!!!!!
this sessionexists, could you specify a bit intenally what happening, does
he consult the reportserver, ...
i'm just lokking for possible path's to find this problem ....
Perhaps try deleting all of the subdirectories from the web cache root
directory.
The WebTier has a global WebSessionManager that manages a list WebSession
objects. A WebSession object has a SessionID (a GUID assigned by the web
session manager). The SessionID corresponds to a subdirectory in the web
cache directory stored on disk. Check out your web cache directory and you
will see the subdirectories with the GUID names.
Checking whether a SessionExists should be extremely quick. The
WebSessionManager has a WebSessionList that internally uses a
stringlist.IndexOf lookup on the sessionID to located the session. If no
session exists a new WebSession is created - along with the corresponding
subdirectory on disk.
Bottom line: We are talking about a stringlist.IndexOf operation and
possibly creating a new subdirectory on disk.
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
I made a mistake thinking that the problem was in the SessionExists, i had a
if-then else-if with in the else-if the
rsWebTier.RequiresAutoSearchParameters(aWebRequest) code. This code takes op
to 12 seconds ....
WebTier Logging
===================================================================================
15:24:07:484 WebTier5480 : D_KINEGROUP\HLEBOEUF ::
15:24:07:484 WebTier5480 : wmMainwaDefaultAction - Start
15:24:07:484 WebTier5480 : ProcessDefaultRequest - Start
15:24:07:484 WebTier5480 : ProcessDefaultRequest - Pass 1
15:24:07:484 WebTier5480 : ProcessDefaultRequest - Pass 2.11
15:24:07:484 WebTier5480 : GetLoginPage - Start
15:24:07:531 WebTier5480 : GetLoginPage - End
15:24:07:531 WebTier5480 : ProcessDefaultRequest - Pass 2.19
15:24:07:531 WebTier5480 : ProcessDefaultRequest - End
15:24:07:531 WebTier5480 : wmMainwaDefaultAction - End
15:24:17:421 WebTier5480 : D_KINEGROUP\HLEBOEUF ::
15:24:17:421 WebTier5480 : wmMainwaLoginAction - Start
15:24:17:421 WebTier5480 : ProcessLoginRequest - Start
15:24:20:109 WebTier5480 : ProcessLoginRequest - End
15:24:20:109 WebTier5480 : wmMainwaLoginAction - End
15:24:36:281 WebTier5480 : D_KINEGROUP\HLEBOEUF ::
content=viewer&volume=Online%20Reports&name=Technical%20Reports%5CComplex%20Day%20Import&folder=v1d0&AccountName=FilledByServer&AccountPassword=&SessionID=%7BBFF86C11%2DE601%2D4E0F%2D94F1%2D48DD382F282B%7D&zoom=100
15:24:36:281 WebTier5480 : wmMainwaDefaultAction - Start
15:24:36:281 WebTier5480 : ProcessDefaultRequest - Start
15:24:36:281 WebTier5480 : ProcessDefaultRequest - Pass 1
15:24:36:281 WebTier5480 : ProcessDefaultRequest - Pass 2.20
15:24:49:531 WebTier5480 : ProcessDefaultRequest - Pass 2.21
15:24:49:531 WebTier5480 : GetAutoSearchParametersPage - Start
15:25:02:703 WebTier5480 : GetSelect_Page (12) - Start
15:25:02:718 WebTier5480 : GetSelect_Page - End
15:25:02:718 WebTier5480 : GetAutoSearchParametersPage - End
15:25:02:718 WebTier5480 : ProcessDefaultRequest - Pass 2.29
15:25:02:718 WebTier5480 : ProcessDefaultRequest - End
15:25:02:718 WebTier5480 : wmMainwaDefaultAction - End
Here is the code that runs the logging
if Debug then LogIt('ProcessDefaultRequest - Pass 1');
Try
if not rsWebTier.SessionExists(aWebRequest) then
begin
if Debug then LogIt('ProcessDefaultRequest - Pass 2.11');
Result := GetLoginPage(aWebRequest);
if Debug then LogIt('ProcessDefaultRequest - Pass 2.19');
end
else
begin
if Debug then LogIt('ProcessDefaultRequest - Pass 2.20');
if rsWebTier.RequiresAutoSearchParameters(aWebRequest) then
begin
if Debug then LogIt('ProcessDefaultRequest - Pass 2.21');
Result := GetAutoSearchParametersPage(aWebRequest);
if Debug then LogIt('ProcessDefaultRequest - Pass 2.29');
end
else
begin
if Debug then LogIt('ProcessDefaultRequest - Pass 2.31');
Result := rsWebTier.ProcessWebRequest(aWebRequest);
if Debug then LogIt('ProcessDefaultRequest - Pass 2.39');
end;
end;
Except
on E: Exception do
begin
LogIt('ProcessDefaultRequest :: ' + E.Message);
Now, this is the Logging of the Report-Server (done with gserver.)
========================================================================
"20050418 15:24:17:453","Session
Start",seInformation,0,,,{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:17:453","Request volume
names",seServiceRequest,1039,GetVolumeNames,"Report
Catalog",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:17:468","Send volume
names",seServiceResponse,966,GetVolumeNames,"Report
Catalog",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:17:468","Request directory: Archived
Reports",seServiceRequest,1085,GetVolumeDirectory,"Report
Catalog",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:17:484","--- DataModuleCreate Start -- ",seInformation,0,,,
"20050418 15:24:17:484","--- DataModuleCreate End -- ",seInformation,0,,,
"20050418 15:24:17:750","--- rsReportArchiveVolumeGetDirectory Start --
",seInformation,0,,,
"20050418 15:24:18:765","--- rsReportArchiveVolumeGetDirectory End --
",seInformation,0,,,
"20050418 15:24:18:765","--- OnDestroy Start -- ",seInformation,0,,,
"20050418 15:24:18:765","--- OnDestroy End -- ",seInformation,0,,,
"20050418 15:24:18:765","Send directory: Archived
Reports",seServiceResponse,53437,GetVolumeDirectory,"Report
Catalog",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:19:359","Request directory: Online
Reports",seServiceRequest,1083,GetVolumeDirectory,"Report
Catalog",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:19:375","--- DataModuleCreate Start -- ",seInformation,0,,,
"20050418 15:24:19:375","--- DataModuleCreate End -- ",seInformation,0,,,
"20050418 15:24:19:390","--- rsReportTemplateVolumeGetDirectory Start --
",seInformation,0,,,
"20050418 15:24:19:406","--- rsReportTemplateVolumeGetDirectory End --
",seInformation,0,,,
"20050418 15:24:19:406","--- OnDestroy Start -- ",seInformation,0,,,
"20050418 15:24:19:406","--- OnDestroy End -- ",seInformation,0,,,
"20050418 15:24:19:406","Send directory: Online
Reports",seServiceResponse,2889,GetVolumeDirectory,"Report
Catalog",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:26:500","Session
End",seInformation,0,,,{42E2B22B-2FF2-4864-BCC5-1BB193FFCEC1}
"20050418 15:24:49:468","Request AutoSearch parameters: Online
Reports\Technical Reports\Complex Day
Import",seServiceRequest,1153,GetAutoSearchParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:24:49:468","--- DataModuleCreate Start -- ",seInformation,0,,,
"20050418 15:24:49:468","--- DataModuleCreate End -- ",seInformation,0,,,
"20050418 15:24:49:468","--- rsReportTemplateVolumeGetDirectory Start --
",seInformation,0,,,
"20050418 15:24:49:484","--- rsReportTemplateVolumeGetDirectory End --
",seInformation,0,,,
"20050418 15:24:49:484","--- OnDestroy Start -- ",seInformation,0,,,
"20050418 15:24:49:484","--- OnDestroy End -- ",seInformation,0,,,
"20050418 15:24:49:484","--- DataModuleCreate Start -- ",seInformation,0,,,
"20050418 15:24:49:484","--- DataModuleCreate End -- ",seInformation,0,,,
"20050418 15:24:49:515","Send AutoSearch parameters: Online
Reports\Technical Reports\Complex Day
Import",seServiceResponse,1305,GetAutoSearchParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:25:02:703","Request report parameters: Online Reports\Technical
Reports\Complex Day
Import",seServiceRequest,1149,GetReportParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:25:02:703","Send report parameters: Online Reports\Technical
Reports\Complex Day
Import",seServiceResponse,989,GetReportParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:25:16:656","Request AutoSearch parameters: Online
Reports\Technical Reports\Complex Day
Import",seServiceRequest,1153,GetAutoSearchParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:25:16:656","Send AutoSearch parameters: Online
Reports\Technical Reports\Complex Day
Import",seServiceResponse,1305,GetAutoSearchParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 15:25:29:984","Request report parameters: Online Reports\Technical
Reports\Complex Day
Import",seServiceRequest,1149,GetReportParameters,"Report
Publishing",{620887D9-FFAD-4116-B051-9A7D856372E0}
"20050418 14:56:17:656","Session
End",seInformation,0,,,{DD0AFFF1-ABFA-4ADB-AC37-7685C3126148}
Conslusion (mine)
====================================================
You can see that the Webtier launches the
rsWebTier.RequiresAutoSearchParameters(aWebRequest) at 15:24:36:281, but the
report-server only starts the "Request AutoSearch parameters" at
15:24:49:468, what happened in these 13 seconds ????
The finding of the report server goes by ip adress, not by naming, but
accessing the report server to get the directories goes very fast !!!!
I just emailed you a unit that may help with debugging. I don't know if you
have some slowness with the report begin loaded on the server? Or perhaps
you have a situation in which a global resource is getting locked by another
thread? For example, if two request related to the same session are received
by the server, then the server has to process them sequentially. The first
request will lock the session and unlock it when it is complete.
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
content=viewer&volume=Online%20Reports&name=Technical%20Reports%5CComplex%20Day%20Import&folder=v1d0&SessionID=%7BF14C56A4%2DD3CF%2D4864%2D84C2%2D6BF48FFB8ADC%7D&zoom=100
14:04:54:765 WebTier4132 : wmMainwaDefaultAction - Start
14:04:54:781 WebTier4132 : ProcessDefaultRequest - Start
14:04:54:781 WebTier4132 : ProcessDefaultRequest - Pass 1
14:04:54:781 ======== TrsWebRequestAdapter.SessionExists -- Start
14:04:54:781 ======== TrsWebRequestAdapter.SessionExists -- Done
14:04:54:781 WebTier4132 : ProcessDefaultRequest - Pass 2.20
14:04:54:781 ======== TrsWebRequestAdapter.RequiresAutoSearchParameters --
Start
14:04:54:781 ======== TrsWebRequestAdapter.ReportExists -- Start
14:04:54:781 ======== TrsWebRequestAdapter.ReportExists -- Done
14:04:54:781 ======== TrsWebRequestAdapter.GetAutoSearchParameters -- Start
14:04:54:781 ======== TrsWebRequestAdapter.CreateClientReport -- Start
14:05:08:375 ======== TrsWebRequestAdapter.CreateClientReport -- Pass 1
14:05:08:375 ======== TrsWebRequestAdapter.CreateClientReport -- Pass 2
14:05:08:375 ======== TrsWebRequestAdapter.CreateClientReport -- Pass 3
14:05:08:375 ======== TrsWebRequestAdapter.CreateClientReport -- Pass 4
14:05:08:375 ======== TrsWebRequestAdapter.CreateClientReport -- Done
14:05:08:437 ======== TrsWebRequestAdapter.GetAutoSearchParameters -- Done
14:05:08:437 ======== TrsWebRequestAdapter.RequiresAutoSearchParameters --
Done
14:05:08:437 WebTier4132 : ProcessDefaultRequest - Pass 2.21
14:05:08:437 WebTier4132 : GetAutoSearchParametersPage - Start
14:05:08:437 ======== TrsWebRequestAdapter.GetReportParameters -- Start
14:05:08:437 ======== TrsWebRequestAdapter.CreateClientReport -- Start
This was the logging, this is the code i've impletented
LogIt('======== TrsWebRequestAdapter.CreateClientReport -- Start');
{create a new client report instance}
lClientReport := TrsClientReport.Create(nil);
LogIt('======== TrsWebRequestAdapter.CreateClientReport -- Pass 1');
{use the session manager to get the session which has the server
connection,
this is necessary because we may be using a server farm}
lSession := gWebSessionManager.GetSessionForRequest(aWebRequest);
LogIt('======== TrsWebRequestAdapter.CreateClientReport -- Pass 2');
And just to mention, the same thing from another computer to the same report
server ...... 5 ms !!!
Just crazy.
I've reinstalled completelly IIS, still the same problem, no firewall
installed (SystemOS is a W2003AS).
If I am understanding the log correctly, the following statement requires 14
seconds to execute?
lClientReport := TrsClientReport.Create(nil);
That should isntantaneous...does not make sense to me at all.
Are you sure the logged times are accurate. Is the loggin thread safe? Are
there other applications or threads running on this machine. Or perhaps
services (database, McAfee, ...).
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
This weekend i will start stripping the server from most of its software
components, and try to look what is causing the problem.
As it is a production machine that's not quite simple to deinstall quite
some operational software.
I'll keep you informed......
Just windows (2003AS), Sql Server (2000Ent) and some Cognos products (Cmm,
Powerplay Server).
Still this problem.
Somewhere i know that this is a networkissue, but no idea how to find out.
Could you be a bit more specific what the CreateClientReport does on
network-access and what kind of protocol on what ports ???
Internally Delphi's TTcpClient compoent is being used.
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
I still couldn't find anything here.
The only thing i could do is reinstall the complete server, but as the
problem happened just like that it could reappear again.
That's why i really would like to find the problem and the only way is to
narrow the scope.
20:22:26:125 ======== TrsClientTcpSocket.GetActive -- Done
20:22:26:125 ======== TrsClientTcpSocket.Connect -- Done
20:22:26:125 ======== TrsClientReport.CancelRequest -- Done
20:22:26:125 ======== TrsClientTcpSocket.Destroy -- Start
20:22:26:125 ======== TrsClientTcpSocket.Destroy -- Done
20:22:26:125 ======== TrsClientReport.Destroy -- Done
20:22:26:125 ======== TrsWebRequestAdapter.GetAutoSearchParameters -- Done
20:22:26:125 ======== TrsWebRequestAdapter.GetReportParameters -- Start
20:22:26:125 ======== TrsWebRequestAdapter.CreateClientReport -- Start
20:22:26:125 ======== TrsClientReport.Create -- Start
20:22:26:125 ======== TrsClientReport.CreatePageGenerator -- Start
20:22:40:593 ======== TrsClientReport.CreatePageGenerator -- Done
20:22:40:593 ======== TrsClientReport.Create -- Done
20:22:40:593 ======== TrsWebRequestAdapter.CreateClientReport -- Pass 1
The delay seems to be in the CreatePageGenerator ......
Do you have somewhere a set of dcu with complete logging on each procedure.
I ask this because it is not my goal to get all of the unit of the
report-server.
I'm feeling a bit guilty on this issue, but until now its my only wat to
find what the f**k is happening with my d**n server.
Kind Regards
Sorry, do not have anything like that...
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
Nard, Many thanks, foudn the problem.
With the source you've send me i could locate that the problem was in the
constructor TrsPageCacheFile.CreateTemp(aCacheDirectory: String);
Then going more and more down i could see that it was the instruction
FDirectoryFileName := ppGetTempFileName(aCacheDirectory, 'rsd');
Looking further i've seen that i had in my \Windows\Temp direcotry 131.526
files (Yes, no typing error)
Deleting all rsd*.* and rsp*.* files left me 36 files !!
And, normal speed !!!!!
I suppose that at a given moment the server crashed and started creating
files, becasue the creation date-hour of 85000 files was within 5 minutes.
Anyhow, Many thanks and finally working again.
Hope that other users having a similar problem can find this so that their
search-period is shorter than mine.
Great news!
--
Nard Moseley
Digital Metaphors Corporation
http://www.digital-metaphors.com
Best regards,
Nard Moseley
Digital Metaphors
www.digital-metaphors.com
Nard, Many thanks, foudn the problem.
With the source you've send me i could locate that the problem was in the
constructor TrsPageCacheFile.CreateTemp(aCacheDirectory: String);
Then going more and more down i could see that it was the instruction
FDirectoryFileName := ppGetTempFileName(aCacheDirectory, 'rsd');
Looking further i've seen that i had in my \Windows\Temp direcotry 131.526
files (Yes, no typing error)
Deleting all rsd*.* and rsp*.* files left me 36 files !!
And, normal speed !!!!!
I suppose that at a given moment the server crashed and started creating
files, becasue the creation date-hour of 85000 files was within 5 minutes.
Anyhow, Many thanks and finally working again.
Hope that other users having a similar problem can find this so that their
search-period is shorter than mine.