Re: Mysterious gap in log files.
Hi! And make sure to put everything in the same file (API, SQL, FLTR, ESCL). That will make it easier to follow. Best Regards - Misi, RRR AB, http://www.rrr.se Products from RRR Scandinavia: * RRR|License - Not enough Remedy licenses? Save money by optimizing. * RRR|Log - Performance issues or elusive bugs? Analyze your Remedy logs. * RRR|Translator - Manage and automate your language translations. Find these products, and many free tools and utilities, at http://rrr.se. I would add in SQL logging. I bet there is some DB activity that makes up for this gap. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of William Rentfrow Sent: Tuesday, April 01, 2008 2:12 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Axton Sent: Tuesday, April 01, 2008 1:07 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ - ** This email and any files transmitted with it are confidential and intended solely for the individual or entity to whom they are addressed. If you have received this email in error destroy it immediately. ** Wal-Mart Confidential ** ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are -- This message was scanned by ESVA and is believed to be clean. ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
Re: Mysterious gap in log files.
Nope. Nothing - I checked that as wellthe longest SQL statement takes about 0.0176 seconds to complete in the entire log and during this time there's no activity. There's literally NOTHING going on - at least none of the log files indicate anything is going on during this time. There's zero activity. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Wes Nichols Sent: Tuesday, April 01, 2008 2:33 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** I would add in SQL logging. I bet there is some DB activity that makes up for this gap. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of William Rentfrow Sent: Tuesday, April 01, 2008 2:12 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Axton Sent: Tuesday, April 01, 2008 1:07 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ** This email and any files transmitted with it are confidential and intended solely for the individual or entity to whom they are addressed. If you have received this email in error destroy it immediately. ** Wal-Mart Confidential ** __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
Re: Mysterious gap in log files
Disregard my last update. This speed problem is caused by Oracle update to the LOBs. In short, I'll be moving them in-row and we'll see what happens. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Wes Nichols Sent: Tuesday, April 01, 2008 2:33 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** I would add in SQL logging. I bet there is some DB activity that makes up for this gap. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of William Rentfrow Sent: Tuesday, April 01, 2008 2:12 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Axton Sent: Tuesday, April 01, 2008 1:07 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ** This email and any files transmitted with it are confidential and intended solely for the individual or entity to whom they are addressed. If you have received this email in error destroy it immediately. ** Wal-Mart Confidential ** __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
Re: Mysterious gap in log files.
What about network delays? Are you moving a large amount of data over the network and that is causing the delay? Just an idea. On Wed, Apr 2, 2008 at 9:12 AM, William Rentfrow [EMAIL PROTECTED] wrote: ** Nope. Nothing - I checked that as wellthe longest SQL statement takes about 0.0176 seconds to complete in the entire log and during this time there's no activity. There's literally NOTHING going on - at least none of the log files indicate anything is going on during this time. There's zero activity. -- *From:* Action Request System discussion list(ARSList) [mailto: [EMAIL PROTECTED] *On Behalf Of *Wes Nichols *Sent:* Tuesday, April 01, 2008 2:33 PM *To:* arslist@ARSLIST.ORG *Subject:* Re: Mysterious gap in log files. ** I would add in SQL logging. I bet there is some DB activity that makes up for this gap. -- *From:* Action Request System discussion list(ARSList) [mailto: [EMAIL PROTECTED] *On Behalf Of *William Rentfrow *Sent:* Tuesday, April 01, 2008 2:12 PM *To:* arslist@ARSLIST.ORG *Subject:* Re: Mysterious gap in log files. ** Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 -- *From:* Action Request System discussion list(ARSList) [mailto: [EMAIL PROTECTED] *On Behalf Of *Axton *Sent:* Tuesday, April 01, 2008 1:07 PM *To:* arslist@ARSLIST.ORG *Subject:* Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ -- *** This email and any files transmitted with it are confidential and intended solely for the individual or entity to whom they are addressed. If you have received this email in error destroy it immediately. ** Wal-Mart Confidential ** * __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
Re: Mysterious gap in log files.
Hi! Please provide us with the surrounding log lines with the full API-call with all FLTR and SQL lines that belongs to that call. The server performs various internal stuff at times, such as refreshing the ar.cfg-file and throwing out inactive users. These type of thing may show as SQL-rows if SQL is involved. Some of these things does not have an RPC ID attached to them. I would be surprised if this happens in the middle of your call. It should be at the beginning or end of the API... Did you have other users that performed things at the same time? It could affect the responsiveness of the database. One such thing could be the locking of the arschema table. Best Regards - Misi, RRR AB, http://rrr.se Nope. Nothing - I checked that as wellthe longest SQL statement takes about 0.0176 seconds to complete in the entire log and during this time there's no activity. There's literally NOTHING going on - at least none of the log files indicate anything is going on during this time. There's zero activity. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Wes Nichols Sent: Tuesday, April 01, 2008 2:33 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** I would add in SQL logging. I bet there is some DB activity that makes up for this gap. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of William Rentfrow Sent: Tuesday, April 01, 2008 2:12 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Axton Sent: Tuesday, April 01, 2008 1:07 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ** This email and any files transmitted with it are confidential and intended solely for the individual or entity to whom they are addressed. If you have received this email in error destroy it immediately
Re: Mysterious gap in log files.
Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
Re: Mysterious gap in log files.
Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Axton Sent: Tuesday, April 01, 2008 1:07 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
Re: Mysterious gap in log files.
I would add in SQL logging. I bet there is some DB activity that makes up for this gap. From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of William Rentfrow Sent: Tuesday, April 01, 2008 2:12 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Unfortunately there's nothing in the API log to show - it calls +CE on HPD:Help Desk to create the entry - the next item in the API log is after the entry is created. That's a 39 second stretch during which the filter items I mentioned are occurring. The snippet below is directly from the filter log - these lines are consecutive - I just shaved off the beginning parts of the lines in my original post for readability. The two consecutive entries from the arfilter log are verbatim below: FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:00.5076 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL FLTR TID: 09 RPC ID: 029441 Queue: Fast Client-RPC: 390620USER: YNZJH0 /* Tue Apr 01 2008 11:08:03.5168 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 094 From: Action Request System discussion list(ARSList) [mailto:[EMAIL PROTECTED] On Behalf Of Axton Sent: Tuesday, April 01, 2008 1:07 PM To: arslist@ARSLIST.ORG Subject: Re: Mysterious gap in log files. ** Post the filter/api log snippets that show the gap with the TID and RPC ID included. Axton On Tue, Apr 1, 2008 at 12:32 PM, William Rentfrow [EMAIL PROTECTED] wrote: ** I am trying to tighten up the time it takes to create a new Incident in IM 7.03 (ARS 7.01, Solaris, remote oracle DB). I've checked the threads/queues quite thoroughly and they appears to be fine - there's plenty of available time queue time. However, in the filter log there are multiple places where this happens: Tue Apr 01 2008 11:08:03.6332 */ End of filter processing (phase 1) -- Operation - CREATE on SYS:Action - NULL Tue Apr 01 2008 11:08:06.6404 */ End of filter processing (phase 2) -- Operation - CREATE on SLM:Measurement - 095 Notice the three second gap between those two - there is NOTHING else going on anywhere else in the SQL or API logs to indicate some processing - it's just three seconds of the nothing in all of the logs. Every time there's a end of filter processing' phase message we just stop for 3 seconds. In my 39-second Incident creation time there are a total of 10 of these gaps - 30 seconds where absolutely nothing appears to be happening. Keep in mind this is a large solaris server and I'm the only one on it - there's no lack of server resources. We've got plenty of hamsters/wheels/etc to power this thing. William Rentfrow, Principal Consultant [EMAIL PROTECTED] C 701-306-6157 O 952-432-0227 __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ __Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are html___ - ** This email and any files transmitted with it are confidential and intended solely for the individual or entity to whom they are addressed. If you have received this email in error destroy it immediately. ** Wal-Mart Confidential ** ___ UNSUBSCRIBE or access ARSlist Archives at www.arslist.org Platinum Sponsor: www.rmsportal.com ARSlist: Where the Answers Are
