Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly
Sign up
Appearance settings

Commit 096d8fa

Browse files
committed
Tracing for Library Discovery
1 parent 35d8e80 commit 096d8fa

File tree

3 files changed

+41
-14
lines changed

3 files changed

+41
-14
lines changed

‎internal/arduino/builder/internal/detector/cache.go‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import (
2121

2222
"github.com/arduino/arduino-cli/internal/arduino/builder/internal/runner"
2323
"github.com/arduino/go-paths-helper"
24+
"github.com/sirupsen/logrus"
2425
)
2526

2627
type detectorCache struct {
@@ -51,6 +52,13 @@ func (e *detectorCacheEntry) String() string {
5152
return "No operation"
5253
}
5354

55+
func (e *detectorCacheEntry) LogMsg() string {
56+
if e.CompileTask == nil {
57+
return e.String()
58+
}
59+
return "Compiling: " + e.Compile.SourcePath.String()
60+
}
61+
5462
func (e *detectorCacheEntry) Equals(entry *detectorCacheEntry) bool {
5563
return e.String() == entry.String()
5664
}
@@ -94,10 +102,15 @@ func (c *detectorCache) Expect(entry *detectorCacheEntry) {
94102
if c.entries[c.curr].Equals(entry) {
95103
// Cache hit, move to the next entry
96104
c.curr++
105+
logrus.Tracef("[LD] CACHE: HIT %s", entry.LogMsg())
97106
return
98107
}
99108
// Cache mismatch, invalidate and cut the remainder of the cache
109+
logrus.Tracef("[LD] CACHE: INVALIDATE %s", entry.LogMsg())
110+
logrus.Tracef("[LD] (was %s)", c.entries[c.curr])
100111
c.entries = c.entries[:c.curr]
112+
} else {
113+
logrus.Tracef("[LD] CACHE: MISSING %s", entry.LogMsg())
101114
}
102115
c.curr++
103116
c.entries = append(c.entries, entry)

‎internal/arduino/builder/internal/detector/detector.go‎

Lines changed: 15 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,7 @@ import (
4141
"github.com/arduino/arduino-cli/internal/i18n"
4242
"github.com/arduino/go-paths-helper"
4343
"github.com/arduino/go-properties-orderedmap"
44+
"github.com/sirupsen/logrus"
4445
)
4546

4647
type libraryResolutionResult struct {
@@ -140,6 +141,7 @@ func (l *SketchLibrariesDetector) ImportedLibraries() libraries.List {
140141
// addAndBuildLibrary adds the given library to the imported libraries list and queues its source files
141142
// for further processing.
142143
func (l *SketchLibrariesDetector) addAndBuildLibrary(sourceFileQueue *uniqueSourceFileQueue, librariesBuildPath *paths.Path, library *libraries.Library) {
144+
logrus.Tracef("[LD] LIBRARY: %s", library.Name)
143145
l.importedLibraries = append(l.importedLibraries, library)
144146
if library.Precompiled && library.PrecompiledWithSources {
145147
// Fully precompiled libraries should have no dependencies to avoid ABI breakage
@@ -202,6 +204,7 @@ func (l *SketchLibrariesDetector) IncludeFoldersChanged() bool {
202204

203205
// addIncludeFolder add the given folder to the include path.
204206
func (l *SketchLibrariesDetector) addIncludeFolder(folder *paths.Path) {
207+
logrus.Tracef("[LD] INCLUDE-PATH: %s", folder.String())
205208
l.includeFolders = append(l.includeFolders, folder)
206209
l.cache.Expect(&detectorCacheEntry{AddedIncludePath: folder})
207210
}
@@ -219,6 +222,11 @@ func (l *SketchLibrariesDetector) FindIncludes(
219222
platformArch string,
220223
jobs int,
221224
) error {
225+
logrus.Debug("Finding required libraries for the sketch.")
226+
defer func() {
227+
logrus.Debugf("Library detection completed. Found %d required libraries.", len(l.importedLibraries))
228+
}()
229+
222230
err := l.findIncludes(ctx, buildPath, buildCorePath, buildVariantPath, sketchBuildPath, sketch, librariesBuildPath, buildProperties, platformArch, jobs)
223231
if err != nil && l.onlyUpdateCompilationDatabase {
224232
l.logger.Info(
@@ -273,7 +281,7 @@ func (l *SketchLibrariesDetector) findIncludes(
273281
l.preRunner = runner.New(ctx, jobs)
274282
for _, entry := range l.cache.EntriesAhead() {
275283
if entry.CompileTask != nil {
276-
upToDate, _ := entry.Compile.ObjFileIsUpToDate()
284+
upToDate, _ := entry.Compile.ObjFileIsUpToDate(logrus.WithField("runner", "prerun"))
277285
if !upToDate {
278286
_ = entry.Compile.PrepareBuildPath()
279287
l.preRunner.Enqueue(entry.CompileTask)
@@ -387,7 +395,7 @@ func (l *SketchLibrariesDetector) findMissingIncludesInCompilationUnit(
387395
// TODO: This reads the dependency file, but the actual building
388396
// does it again. Should the result be somehow cached? Perhaps
389397
// remove the object file if it is found to be stale?
390-
unchanged, err := sourceFile.ObjFileIsUpToDate()
398+
unchanged, err := sourceFile.ObjFileIsUpToDate(logrus.WithField("runner", "main"))
391399
if err != nil {
392400
return err
393401
}
@@ -403,11 +411,13 @@ func (l *SketchLibrariesDetector) findMissingIncludesInCompilationUnit(
403411
var missingIncludeH string
404412
if entry := l.cache.Peek(); unchanged && entry != nil && entry.MissingIncludeH != nil {
405413
missingIncludeH = *entry.MissingIncludeH
414+
logrus.Tracef("[LD] COMPILE-CACHE: %s", sourceFile.SourcePath)
406415
if first && l.logger.VerbosityLevel() == logger.VerbosityVerbose {
407416
l.logger.Info(i18n.Tr("Using cached library dependencies for file: %[1]s", sourcePath))
408417
}
409418
first = false
410419
} else {
420+
logrus.Tracef("[LD] COMPILE: %s", sourceFile.SourcePath)
411421
if l.preRunner != nil {
412422
if r := l.preRunner.Results(preprocTask); r != nil {
413423
preprocResult = r
@@ -448,6 +458,7 @@ func (l *SketchLibrariesDetector) findMissingIncludesInCompilationUnit(
448458
}
449459
}
450460

461+
logrus.Tracef("[LD] MISSING: %s", missingIncludeH)
451462
l.cache.Expect(&detectorCacheEntry{MissingIncludeH: &missingIncludeH})
452463

453464
if missingIncludeH == "" {
@@ -495,6 +506,8 @@ func (l *SketchLibrariesDetector) queueSourceFilesFromFolder(
495506
buildDir *paths.Path,
496507
extraIncludePath ...*paths.Path,
497508
) error {
509+
logrus.Tracef("[LD] SCAN: %s (recurse=%v)", folder, recurse)
510+
498511
sourceFileExtensions := []string{}
499512
for k := range globals.SourceFilesValidExtensions {
500513
sourceFileExtensions = append(sourceFileExtensions, k)

‎internal/arduino/builder/internal/detector/source_file.go‎

Lines changed: 13 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -62,60 +62,60 @@ func (f *sourceFile) PrepareBuildPath() error {
6262
}
6363

6464
// ObjFileIsUpToDate checks if the compile object file is up to date.
65-
func (f *sourceFile) ObjFileIsUpToDate() (unchanged bool, err error) {
66-
logrus.Debugf("Checking previous results for %v (dep = %v)", f.SourcePath, f.DepfilePath)
65+
func (f *sourceFile) ObjFileIsUpToDate(log *logrus.Entry) (unchanged bool, err error) {
6766
if f.DepfilePath == nil {
68-
logrus.Debugf(" Object file or dependency file not provided")
67+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: object file or dependency file not provided", f.SourcePath)
6968
return false, nil
7069
}
7170

7271
sourceFile := f.SourcePath.Clean()
7372
sourceFileStat, err := sourceFile.Stat()
7473
if err != nil {
75-
logrus.Debugf(" Could not stat source file: %s", err)
74+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: Could not stat source file: %s", f.SourcePath, err)
7675
return false, err
7776
}
7877
dependencyFile := f.DepfilePath.Clean()
7978
dependencyFileStat, err := dependencyFile.Stat()
8079
if err != nil {
8180
if os.IsNotExist(err) {
82-
logrus.Debugf(" Dependency file not found: %v", dependencyFile)
81+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: Dependency file not found: %v", f.SourcePath, dependencyFile)
8382
return false, nil
8483
}
85-
logrus.Debugf(" Could not stat dependency file: %s", err)
84+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: Could not stat dependency file: %s", f.SourcePath, err)
8685
return false, err
8786
}
8887
if sourceFileStat.ModTime().After(dependencyFileStat.ModTime()) {
89-
logrus.Debugf(" %v newer than %v", sourceFile, dependencyFile)
88+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: %v newer than %v", f.SourcePath, sourceFile, dependencyFile)
9089
return false, nil
9190
}
9291
deps, err := cpp.ReadDepFile(dependencyFile)
9392
if err != nil {
94-
logrus.Debugf(" Could not read dependency file: %s", dependencyFile)
93+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: Could not read dependency file: %s", f.SourcePath, dependencyFile)
9594
return false, err
9695
}
9796
if len(deps.Dependencies) == 0 {
9897
return true, nil
9998
}
10099
if deps.Dependencies[0] != sourceFile.String() {
101-
logrus.Debugf(" Depfile is about different source file: %v (expected %v)", deps.Dependencies[0], sourceFile)
100+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: Depfile is about different source file: %v (expected %v)", f.SourcePath, deps.Dependencies[0], sourceFile)
102101
return false, nil
103102
}
104103
for _, dep := range deps.Dependencies[1:] {
105104
depStat, err := os.Stat(dep)
106105
if os.IsNotExist(err) {
107-
logrus.Debugf(" Not found: %v", dep)
106+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: Not found: %v", f.SourcePath, dep)
108107
return false, nil
109108
}
110109
if err != nil {
111-
logrus.WithError(err).Debugf(" Failed to read: %v", dep)
110+
logrus.WithError(err).Tracef("[LD] COMPILE-CHECK: REBUILD %v: Failed to read: %v", f.SourcePath, dep)
112111
return false, nil
113112
}
114113
if depStat.ModTime().After(dependencyFileStat.ModTime()) {
115-
logrus.Debugf(" %v newer than %v", dep, dependencyFile)
114+
log.Tracef("[LD] COMPILE-CHECK: REBUILD %v: %v newer than %v", f.SourcePath, dep, dependencyFile)
116115
return false, nil
117116
}
118117
}
118+
log.Tracef("[LD] COMPILE-CHECK: REUSE %v Up-to-date", f.SourcePath)
119119
return true, nil
120120
}
121121

@@ -125,6 +125,7 @@ type uniqueSourceFileQueue []sourceFile
125125
// Push adds a source file to the queue if it is not already present.
126126
func (queue *uniqueSourceFileQueue) Push(value sourceFile) {
127127
if !queue.Contains(value) {
128+
logrus.Tracef("[LD] QUEUE: Added %s", value.SourcePath)
128129
*queue = append(*queue, value)
129130
}
130131
}

0 commit comments

Comments
(0)

AltStyle によって変換されたページ (->オリジナル) /