Emit warning if require will not comply with specification (#3681)

part of #3534

Co-authored-by: Joan López de la Franca Beltran <5459617+joanlopez@users.noreply.github.com>

js/modules/require_impl.go

@@ -28,15 +28,19 @@ func NewLegacyRequireImpl(vu VU, ms *ModuleSystem, pwd url.URL) *LegacyRequireIm
 	}
 }
 
+const issueLink = "https://github.com/grafana/k6/issues/3534"
+
 // Require is the actual call that implements require
 func (r *LegacyRequireImpl) Require(specifier string) (*goja.Object, error) {
 	// TODO remove this in the future when we address https://github.com/grafana/k6/issues/2674
 	// This is currently needed as each time require is called we need to record it's new pwd
 	// to be used if a require *or* open is used within the file as they are relative to the
 	// latest call to require.
+	//
 	// This is *not* the actual require behaviour defined in commonJS as it is actually always relative
 	// to the file it is in. This is unlikely to be an issue but this code is here to keep backwards
 	// compatibility *for now*.
+	//
 	// With native ESM this won't even be possible as `require` might not be called - instead an import
 	// might be used in which case we won't be able to be doing this hack. In that case we either will
 	// need some goja specific helper or to use stack traces as goja_nodejs does.
@@ -48,6 +52,9 @@ func (r *LegacyRequireImpl) Require(specifier string) (*goja.Object, error) {
 		// In theory we can give that downwards, but this makes the code more tightly coupled
 		// plus as explained above this will be removed in the future so the code reflects more
 		// closely what will be needed then
+		if !r.modules.resolver.locked {
+			r.warnUserOnPathResolutionDifferences(specifier)
+		}
 		fileURL, err := loader.Resolve(r.currentlyRequiredModule, specifier)
 		if err != nil {
 			return nil, err
@@ -67,3 +74,81 @@ func (r *LegacyRequireImpl) Require(specifier string) (*goja.Object, error) {
 func (r *LegacyRequireImpl) CurrentlyRequiredModule() url.URL {
 	return *r.currentlyRequiredModule
 }
+
+func (r *LegacyRequireImpl) warnUserOnPathResolutionDifferences(specifier string) {
+	normalizePathToURL := func(path string) (*url.URL, error) {
+		u, err := url.Parse(path)
+		if err != nil {
+			return nil, err
+		}
+		return loader.Dir(u), nil
+	}
+	// Warn users on their require depending on the none standard k6 behaviour.
+	rt := r.vu.Runtime()
+	logger := r.vu.InitEnv().Logger
+	correct, err := normalizePathToURL(getCurrentModuleScript(rt))
+	if err != nil {
+		logger.Warningf("Couldn't get the \"correct\" path to resolve specifier %q against: %q"+
+			"Please report to issue %s. "+
+			"This will not currently break your script but it might mean that in the future it won't work",
+			specifier, err, issueLink)
+	} else if r.currentlyRequiredModule.String() != correct.String() {
+		logger.Warningf("The \"wrong\" path (%q) and the path actually used by k6 (%q) to resolve %q are different. "+
+			"Please report to issue %s. "+
+			"This will not currently break your script but *WILL* in the future, please report this!!!",
+			correct, r.currentlyRequiredModule, specifier, issueLink)
+	}
+
+	k6behaviourString, err := getPreviousRequiringFile(rt)
+	if err != nil {
+		logger.Warningf("Couldn't get the \"wrong\" path to resolve specifier %q against: %q"+
+			"Please report to issue %s. "+
+			"This will not currently break your script but it might mean that in the future it won't work",
+			specifier, err, issueLink)
+		return
+	}
+	k6behaviour, err := normalizePathToURL(k6behaviourString)
+	if err != nil {
+		logger.Warningf("Couldn't get the \"wrong\" path to resolve specifier %q against: %q"+
+			"Please report to issue %s. "+
+			"This will not currently break your script but it might mean that in the future it won't work",
+			specifier, err, issueLink)
+		return
+	}
+	if r.currentlyRequiredModule.String() != k6behaviour.String() {
+		// this should always be equal, but check anyway to be certain we won't break something
+		logger.Warningf("The \"wrong\" path (%q) and the path actually used by k6 (%q) to resolve %q are different. "+
+			"Please report to issue %s. "+
+			"This will not currently break your script but it might mean that in the future it won't work",
+			k6behaviour, r.currentlyRequiredModule, specifier, issueLink)
+	}
+}
+
+func getCurrentModuleScript(rt *goja.Runtime) string {
+	var parent string
+	var buf [2]goja.StackFrame
+	frames := rt.CaptureCallStack(2, buf[:0])
+	parent = frames[1].SrcName()
+
+	return parent
+}
+
+func getPreviousRequiringFile(rt *goja.Runtime) (string, error) {
+	var buf [1000]goja.StackFrame
+	frames := rt.CaptureCallStack(1000, buf[:0])
+
+	for i, frame := range frames[1:] { // first one should be the current require
+		// TODO have this precalculated automatically
+		if frame.FuncName() == "go.k6.io/k6/js.(*requireImpl).require-fm" {
+			// we need to get the one *before* but as we skip the first one the index matches ;)
+			return frames[i].SrcName(), nil
+		}
+	}
+	// hopefully nobody is calling `require` with 1000 big stack :crossedfingers:
+	if len(frames) == 1000 {
+		return "", errors.New("stack too big")
+	}
+
+	// fallback
+	return frames[len(frames)-1].SrcName(), nil
+}

js/path_resolution_test.go

@@ -4,8 +4,10 @@ import (
 	"context"
 	"testing"
 
+	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/require"
 	"go.k6.io/k6/lib/fsext"
+	"go.k6.io/k6/lib/testutils"
 )
 
 // This whole file is about tests around https://github.com/grafana/k6/issues/2674
@@ -70,6 +72,7 @@ func TestOpenPathResolution(t *testing.T) {
 			t.Parallel()
 			fs := fsext.NewMemMapFs()
 			err := writeToFs(fs, testCase.fsMap)
+			fs = fsext.NewCacheOnReadFs(fs, fsext.NewMemMapFs(), 0)
 			require.NoError(t, err)
 			b, err := getSimpleBundle(t, "/main.js", `export { default } from "/A/A/A/A/script.js"`, fs)
 			require.NoError(t, err)
@@ -83,7 +86,8 @@ func TestOpenPathResolution(t *testing.T) {
 func TestRequirePathResolution(t *testing.T) {
 	t.Parallel()
 	testCases := map[string]struct {
-		fsMap map[string]any
+		fsMap        map[string]any
+		expectedLogs []string
 	}{
 		"simple": {
 			fsMap: map[string]any{
@@ -130,6 +134,9 @@ func TestRequirePathResolution(t *testing.T) {
 					export default function() {}
 				`,
 			},
+			expectedLogs: []string{
+				`The "wrong" path ("file:///A/C/B/") and the path actually used by k6 ("file:///A/B/B/") to resolve "./../data.js" are different`,
+			},
 		},
 		"ESM and require": {
 			fsMap: map[string]any{
@@ -152,6 +159,9 @@ func TestRequirePathResolution(t *testing.T) {
 					export default function() {}
 				`,
 			},
+			expectedLogs: []string{
+				`The "wrong" path ("file:///A/C/B/") and the path actually used by k6 ("file:///A/B/B/") to resolve "./../data.js" are different`,
+			},
 		},
 		"full ESM": {
 			fsMap: map[string]any{
@@ -175,6 +185,9 @@ func TestRequirePathResolution(t *testing.T) {
 					export default function() {}
 				`,
 			},
+			expectedLogs: []string{
+				`The "wrong" path ("file:///A/C/B/") and the path actually used by k6 ("file:///A/B/B/") to resolve "./../data.js" are different`,
+			},
 		},
 	}
 	for name, testCase := range testCases {
@@ -184,12 +197,25 @@ func TestRequirePathResolution(t *testing.T) {
 			t.Parallel()
 			fs := fsext.NewMemMapFs()
 			err := writeToFs(fs, testCase.fsMap)
+			fs = fsext.NewCacheOnReadFs(fs, fsext.NewMemMapFs(), 0)
 			require.NoError(t, err)
-			b, err := getSimpleBundle(t, "/main.js", `export { default } from "/A/A/A/A/script.js"`, fs)
+			logger, hook := testutils.NewLoggerWithHook(t, logrus.WarnLevel)
+			b, err := getSimpleBundle(t, "/main.js", `export { default } from "/A/A/A/A/script.js"`, fs, logger)
 			require.NoError(t, err)
 
 			_, err = b.Instantiate(context.Background(), 0)
 			require.NoError(t, err)
+			logs := hook.Drain()
+
+			if len(testCase.expectedLogs) == 0 {
+				require.Empty(t, logs)
+				return
+			}
+			require.Equal(t, len(logs), len(testCase.expectedLogs))
+
+			for i, log := range logs {
+				require.Contains(t, log.Message, testCase.expectedLogs[i], "log line %d", i)
+			}
 		})
 	}
 }