I''ve been testing the build 18 OpenSolaris bits with the DTrace test suite. I did two runs on my amd64 box, and in one run the index test failed with dtrace: error on enabled probe ID 1 (ID 1: dtrace:::BEGIN): invalid address (0xffffffff882bf040) in action #16 at DIF offset 52 Any ideas as to what could be causing this? mike
Howdy, I was playing with the Solaris internals fsflush.d DTRACE script: http://www.solarisinternals.com/si/dtrace/fsflush.d Which produces the following results on my Solaris 10 box: $ fsflush.d SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES TIME(ns) 4254 4255 1 1 0 0 2695024 4254 4255 1 0 0 0 1921518 4254 3744 80 25 0 0 2394895 How can pages "SCANNED" be less than pages "EXAMINED?" Also, does "fsf_total.fsf_time - ltime" calculate the time it took fsflush to scan "SCANNED" pages ( I assume so, but don''t like to assume anything )? Thanks for any insight! - Ryan
Hi Ryan,> I was playing with the Solaris internals fsflush.d DTRACE script: > > http://www.solarisinternals.com/si/dtrace/fsflush.d > > Which produces the following results on my Solaris 10 box: > > $ fsflush.d > SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES TIME(ns) > 4254 4255 1 1 0 0 2695024 > 4254 4255 1 0 0 0 1921518 > 4254 3744 80 25 0 0 2394895 > > How can pages "SCANNED" be less than pages "EXAMINED?" Also, does > "fsf_total.fsf_time - ltime" calculate the time it took fsflush to scan > "SCANNED" pages ( I assume so, but don''t like to assume anything )?The number of pages examined can be less than that scanned owing to the fact that we only examine 1 page_t in a large page and skip over the other sub-pages within such a page: Check out: http://cvs.opensolaris.org/source/xref/usr/src/uts/common/fs/fsflush.c#fsflush_do_pages And yes, "fsf_total.fsf_time - ltime" is the time taken to scan SCANNED pages. Cheers. Jon.
I think he''s concerned with the first two results where pages examined is greater than pages scanned. What conditions could cause this to occur? Cheers, Ben On 21/07/2005, at 1:09 AM, Jonathan Haslam wrote:> Hi Ryan, > > >> I was playing with the Solaris internals fsflush.d DTRACE script: >> >> http://www.solarisinternals.com/si/dtrace/fsflush.d >> >> Which produces the following results on my Solaris 10 box: >> >> $ fsflush.d >> SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES >> TIME(ns) >> 4254 4255 1 1 0 0 >> 2695024 >> 4254 4255 1 0 0 0 >> 1921518 >> 4254 3744 80 25 0 0 >> 2394895 >> >> How can pages "SCANNED" be less than pages "EXAMINED?" Also, does >> "fsf_total.fsf_time - ltime" calculate the time it took fsflush to >> scan >> "SCANNED" pages ( I assume so, but don''t like to assume anything )? >> > > The number of pages examined can be less than that scanned owing to > the fact that we only examine 1 page_t in a large page and skip over > the other sub-pages within such a page: > > Check out: > > http://cvs.opensolaris.org/source/xref/usr/src/uts/common/fs/ > fsflush.c#fsflush_do_pages > > And yes, "fsf_total.fsf_time - ltime" is the time taken to scan > SCANNED > pages. > > > Cheers. > > Jon. > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org >
> I think he''s concerned with the first two results where pages > examined is greater than pages scanned. What conditions could cause > this to occur?Doh! I guess I should actually read what the question is before replying ... This is a bug in fsflush. We do one too many iterations in the loop when we go over the pages we''re scanning. It''s fairly harmless but just means that we scan one page too many each time. The number of pages examined exceeds the number of pages scanned when all the pages scanned are of the base page size for the machine (no large pages). With a whopping one character fix the output now looks like: SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES 62467 62467 6112 1768 0 0 7757904 62467 62467 11560 11498 0 0 13494728 62467 62467 310 301 0 0 6600491 Thanks for pointing this out. I''ll log the bug. Cheers. Jon.> > > Cheers, > Ben > > On 21/07/2005, at 1:09 AM, Jonathan Haslam wrote: > >> Hi Ryan, >> >> >>> I was playing with the Solaris internals fsflush.d DTRACE script: >>> >>> http://www.solarisinternals.com/si/dtrace/fsflush.d >>> >>> Which produces the following results on my Solaris 10 box: >>> >>> $ fsflush.d >>> SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES >>> TIME(ns) >>> 4254 4255 1 1 0 0 >>> 2695024 >>> 4254 4255 1 0 0 0 >>> 1921518 >>> 4254 3744 80 25 0 0 >>> 2394895 >>> >>> How can pages "SCANNED" be less than pages "EXAMINED?" Also, does >>> "fsf_total.fsf_time - ltime" calculate the time it took fsflush to >>> scan >>> "SCANNED" pages ( I assume so, but don''t like to assume anything )? >>> >> >> The number of pages examined can be less than that scanned owing to >> the fact that we only examine 1 page_t in a large page and skip over >> the other sub-pages within such a page: >> >> Check out: >> >> http://cvs.opensolaris.org/source/xref/usr/src/uts/common/fs/ >> fsflush.c#fsflush_do_pages >> >> And yes, "fsf_total.fsf_time - ltime" is the time taken to scan SCANNED >> pages. >> >> >> Cheers. >> >> Jon. >> >> _______________________________________________ >> dtrace-discuss mailing list >> dtrace-discuss at opensolaris.org >> > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org
I forgot to thank Andy "lightning build" Bowers for his help with verifying this. He can build and test a kernel faster than I can ftp one from home to my lab! Cheers. Jon.> >> I think he''s concerned with the first two results where pages >> examined is greater than pages scanned. What conditions could cause >> this to occur? > > > > Doh! I guess I should actually read what the question is before > replying ... > > This is a bug in fsflush. We do one too many iterations in the loop when > we go over the pages we''re scanning. It''s fairly harmless but just > means that we scan one page too many each time. The number of pages > examined exceeds the number of pages scanned when all the pages > scanned are of the base page size for the machine (no large pages). > > With a whopping one character fix the output now looks like: > > SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES > 62467 62467 6112 1768 0 0 7757904 > 62467 62467 11560 11498 0 0 > 13494728 > 62467 62467 310 301 0 0 > 6600491 > > Thanks for pointing this out. I''ll log the bug. > > > Cheers. > > Jon. > >> >> >> Cheers, >> Ben >> >> On 21/07/2005, at 1:09 AM, Jonathan Haslam wrote: >> >>> Hi Ryan, >>> >>> >>>> I was playing with the Solaris internals fsflush.d DTRACE script: >>>> >>>> http://www.solarisinternals.com/si/dtrace/fsflush.d >>>> >>>> Which produces the following results on my Solaris 10 box: >>>> >>>> $ fsflush.d >>>> SCANNED EXAMINED LOCKED MODIFIED COALESCE RELEASES >>>> TIME(ns) >>>> 4254 4255 1 1 0 0 >>>> 2695024 >>>> 4254 4255 1 0 0 0 >>>> 1921518 >>>> 4254 3744 80 25 0 0 >>>> 2394895 >>>> >>>> How can pages "SCANNED" be less than pages "EXAMINED?" Also, does >>>> "fsf_total.fsf_time - ltime" calculate the time it took fsflush to >>>> scan >>>> "SCANNED" pages ( I assume so, but don''t like to assume anything )? >>>> >>> >>> The number of pages examined can be less than that scanned owing to >>> the fact that we only examine 1 page_t in a large page and skip over >>> the other sub-pages within such a page: >>> >>> Check out: >>> >>> http://cvs.opensolaris.org/source/xref/usr/src/uts/common/fs/ >>> fsflush.c#fsflush_do_pages >>> >>> And yes, "fsf_total.fsf_time - ltime" is the time taken to scan >>> SCANNED >>> pages. >>> >>> >>> Cheers. >>> >>> Jon. >>> >>> _______________________________________________ >>> dtrace-discuss mailing list >>> dtrace-discuss at opensolaris.org >>> >> >> _______________________________________________ >> dtrace-discuss mailing list >> dtrace-discuss at opensolaris.org > > > > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org