Created
November 16, 2023 10:27
-
-
Save pillowtrucker/bb5663e93af5c77f19dc47c41a637b40 to your computer and use it in GitHub Desktop.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| global theStats[64] | |
| global theShorts[100] | |
| global theErrors[64] | |
| global timestamps[64] | |
| global aggTotalNFSRead | |
| global aggTotalXFSRead | |
| global aggGenericFileRead | |
| global aggNFSConcurrency | |
| global currentConcurrency[10] | |
| probe module("nfsd").function("nfsd_splice_read") { | |
| caller = "nfsd_splice_read" | |
| wantCount = kernel_long($count) | |
| theFilename = fullpath_struct_path(&$file->f_path) | |
| offAsStr = sprintf("%d",$offset) | |
| myKey = caller . theFilename . offAsStr | |
| # printf("[ENTER NFSD] Why the heck does nothing match %s.",myKey) | |
| # printf("Process %d ( %s ) wanted to read %d bytes from file %s at offset %d\n",pid(),execname(),wantCount,theFilename,$offset) | |
| theStats[myKey] = wantCount; | |
| if (theFilename in currentConcurrency) { | |
| currentConcurrency[theFilename]++ | |
| } | |
| else { | |
| currentConcurrency[theFilename] = 1 | |
| } | |
| aggNFSConcurrency[theFilename] <<< currentConcurrency[theFilename] | |
| timestamps[myKey] = gettimeofday_us() | |
| } | |
| probe module("xfs").function("xfs_file_buffered_aio_read") { | |
| caller = "xfs_file_buffered_aio_read" | |
| theFilename = fullpath_struct_path(&$iocb->ki_filp->f_path) | |
| theOffset = $iocb->ki_pos | |
| offAsStr = sprintf("%d",theOffset) | |
| wtf = "nfsd_splice_read" . theFilename . offAsStr | |
| # printf("[ENTER XFS] Why the heck does nothing match %s.",wtf) | |
| if (wtf in timestamps) { | |
| # printf("On xfs read hook enter found existing nfsd transaction for file %s at offset %d.\n",theFilename,theOffset) | |
| } | |
| else { | |
| # printf("Ignoring xfs read for file %s at offset %d with no matching nfsd transaction.\n",theFilename,theOffset) | |
| next | |
| } | |
| myKey = caller . theFilename . offAsStr | |
| # printf("Process %d ( %s ) started xfs read from file %s at offset %d.\n",pid(),execname(),theFilename,theOffset) | |
| timestamps[myKey] = gettimeofday_us() | |
| } | |
| probe module("xfs").function("xfs_file_buffered_aio_read").return { | |
| caller = "xfs_file_buffered_aio_read" | |
| theFilename = fullpath_struct_path(&$iocb->ki_filp->f_path) | |
| theOffset = $iocb->ki_pos | |
| offAsStr = sprintf("%d",theOffset) | |
| wtf = "nfsd_splice_read" . theFilename . offAsStr | |
| if (wtf in timestamps) { | |
| # printf("On xfs read hook return found existing nfsd transaction for file %s at offset %d.\n",theFilename,theOffset) | |
| } | |
| else { | |
| # printf("Ignoring xfs read return for file %s at offset %d with no matching nfsd transaction.\n",theFilename,theOffset) | |
| next | |
| } | |
| myKey = caller . theFilename . offAsStr | |
| myRunTime = gettimeofday_us() - timestamps[myKey] | |
| aggTotalXFSRead[theFilename] <<< myRunTime | |
| delete timestamps[myKey] | |
| printf("Process %d ( %s ) finished xfs read from file %s at offset %d in about %d microseconds.\n",pid(),execname(),theFilename,theOffset,myRunTime) | |
| } | |
| probe kernel.function("generic_file_read_iter") { | |
| caller = "generic_file_read_iter" | |
| theFilename = fullpath_struct_path(&$iocb->ki_filp->f_path) | |
| theOffset = $iocb->ki_pos | |
| offAsStr = sprintf("%d",theOffset) | |
| wtf = "nfsd_splice_read" . theFilename . offAsStr | |
| if (wtf in timestamps) { | |
| # printf("On generic read hook enter found existing nfsd transaction for file %s at offset %d.\n",theFilename,theOffset) | |
| } | |
| else { | |
| # printf("Ignoring generic read for file %s at offset %d with no matching nfsd transaction.\n",theFilename,theOffset) | |
| next | |
| } | |
| myKey = caller . theFilename . offAsStr | |
| # printf("Process %d ( %s ) started generic read from file %s at offset %d.\n",pid(),execname(),theFilename,theOffset) | |
| timestamps[myKey] = gettimeofday_us() | |
| } | |
| probe kernel.function("generic_file_read_iter").return { | |
| caller = "generic_file_read_iter" | |
| theFilename = fullpath_struct_path(&$iocb->ki_filp->f_path) | |
| theOffset = $iocb->ki_pos | |
| offAsStr = sprintf("%d",theOffset) | |
| wtf = "nfsd_splice_read" . theFilename . offAsStr | |
| if (wtf in timestamps) { | |
| # printf("On generic read hook return found existing nfsd transaction for file %s at offset %d.\n",theFilename,theOffset) | |
| } | |
| else { | |
| # printf("Ignoring generic read return for file %s at offset %d with no matching nfsd transaction.\n",theFilename,theOffset) | |
| next | |
| } | |
| myKey = caller . theFilename . offAsStr | |
| myRunTime = gettimeofday_us() - timestamps[myKey] | |
| aggGenericFileRead[theFilename] <<< myRunTime | |
| delete timestamps[myKey] | |
| printf("Process %d ( %s ) finished generic read from file %s at offset %d in about %d microseconds.\n",pid(),execname(),theFilename,theOffset,myRunTime) | |
| } | |
| probe module("nfsd").function("nfsd_splice_read").return { | |
| caller = "nfsd_splice_read" | |
| theFilename = fullpath_struct_path(&$file->f_path) | |
| offAsStr = sprintf("%d",$offset) | |
| myKey = caller . theFilename . offAsStr | |
| myRunTime = gettimeofday_us() - timestamps[myKey] | |
| currentConcurrency[theFilename]-- | |
| aggNFSConcurrency[theFilename] <<< currentConcurrency[theFilename] | |
| if ($return == 0) { | |
| gotCount = kernel_long($count) | |
| tally = theStats[myKey] - gotCount; | |
| if (tally == 0) { | |
| printf("Process %d ( %s ) finished read %d bytes from file %s at offset %d matching with requested length, this took about %d microseconds.\n",pid(),execname(),gotCount,theFilename,$offset,myRunTime) | |
| } | |
| else { | |
| theShorts[myKey] = tally; | |
| printf("Process %d ( %s ) finished read %d bytes from file %s at offset %d with read short by %d bytes, this took about %d microseconds.\n",pid(),execname(),gotCount,theFilename,$offset,tally,myRunTime) | |
| } | |
| } | |
| else { | |
| theErrors[myKey] = tally; | |
| printf("Process %d ( %s ) got error in read with code %d in file %s at offset %d, this took about %d microseconds.\n",pid(),execname(),$return,theFilename,$offset,myRunTime) | |
| } | |
| aggTotalNFSRead[theFilename] <<< myRunTime | |
| delete theStats[myKey] | |
| delete timestamps[myKey] | |
| } | |
| probe end { | |
| printf("Statistics:\n") | |
| foreach (k in aggNFSConcurrency) { | |
| maxC = @max(aggNFSConcurrency[k]) | |
| avgC = @avg(aggNFSConcurrency[k]) | |
| printf("%s maximum concurrency %d, average %d.\n",k,maxC,avgC) | |
| } | |
| foreach (k in aggTotalNFSRead) { | |
| maxRT = @max(aggTotalNFSRead[k]) | |
| avgRT = @avg(aggTotalNFSRead[k]) | |
| printf("%s maximum nfs read time per chunk %d microseconds, average %d microseconds.\n",k,maxRT,avgRT) | |
| } | |
| foreach (k in aggTotalXFSRead) { | |
| maxRT = @max(aggTotalXFSRead[k]) | |
| avgRT = @avg(aggTotalXFSRead[k]) | |
| printf("%s maximum xfs read time per chunk %d microseconds, average %d microseconds.\n",k,maxRT,avgRT) | |
| } | |
| foreach (k in aggGenericFileRead) { | |
| maxRT = @max(aggGenericFileRead[k]) | |
| avgRT = @avg(aggGenericFileRead[k]) | |
| printf("%s maximum generic read time per chunk %d microseconds, average %d microseconds.\n",k,maxRT,avgRT) | |
| } | |
| printf("Error summary:\n") | |
| foreach (k in theShorts) { | |
| v = theShorts[k] | |
| printf("%s short %d bytes.\n",k,v) | |
| } | |
| foreach (k in theErrors) { | |
| v = theErrors[k] | |
| printf("%s error code %d.\n",k,v) | |
| } | |
| foreach (k in theStats) { | |
| v = theStats[k] | |
| printf("Read of %s not finished by end of trace while reading %d bytes",k,v) | |
| if (k in timestamps) { | |
| printf(" with last timestamp %d.",timestamps[k]) | |
| } | |
| else { | |
| printf(" with no known last timestamp.") | |
| } | |
| printf("\n") | |
| } | |
| } |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment