Skip to content

Commit ed6dc8e

Browse files
committed
[js] Log a warning if the user creates a managed promise or schedules an
unchained task (which relies on the promise manager for proper synchronization). See CHANGES.md for instructions on printing these messages to the console. These changes are intended to help users find code that still relies on the promise manager (#2969, #3062)
1 parent 9f39acd commit ed6dc8e

File tree

2 files changed

+82
-13
lines changed

2 files changed

+82
-13
lines changed

javascript/node/selenium-webdriver/CHANGES.md

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,16 @@
1+
## v.next
2+
3+
* Added warning log messages when the user creates new managed promises, or
4+
schedules unchained tasks. Users may opt in to printing these log messages
5+
with
6+
7+
```js
8+
const {logging} = require('selenium-webdriver');
9+
logging.installConsoleHandler();
10+
logging.getLogger('promise.ControlFlow').setLevel(logging.Level.WARNING);
11+
```
12+
13+
114
## v3.1.0
215

316
* The `lib` package is once again platform agnostic (excluding `lib/devmode`).
@@ -17,6 +30,7 @@
1730
* Use the proper wire command for WebElement.getLocation() and
1831
WebElement.getSize() for W3C compliant drivers.
1932

33+
2034
## v3.0.1
2135

2236
* More API adjustments to align with native Promises

javascript/node/selenium-webdriver/lib/promise.js

Lines changed: 68 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1003,6 +1003,9 @@ const PromiseState = {
10031003
*/
10041004
const ON_CANCEL_HANDLER = new WeakMap;
10051005

1006+
const SKIP_LOG = Symbol('skip-log');
1007+
const FLOW_LOG = logging.getLogger('promise.ControlFlow');
1008+
10061009

10071010
/**
10081011
* Represents the eventual value of a completed operation. Each promise may be
@@ -1025,14 +1028,29 @@ class ManagedPromise {
10251028
* functions, one for fulfilling the promise and another for rejecting it.
10261029
* @param {ControlFlow=} opt_flow The control flow
10271030
* this instance was created under. Defaults to the currently active flow.
1031+
* @param {?=} opt_skipLog An internal parameter used to skip logging the
1032+
* creation of this promise. This parameter has no effect unless it is
1033+
* strictly equal to an internal symbol. In other words, this parameter
1034+
* is always ignored for external code.
10281035
*/
1029-
constructor(resolver, opt_flow) {
1036+
constructor(resolver, opt_flow, opt_skipLog) {
10301037
if (!usePromiseManager()) {
10311038
throw TypeError(
10321039
'Unable to create a managed promise instance: the promise manager has'
10331040
+ ' been disabled by the SELENIUM_PROMISE_MANAGER environment'
10341041
+ ' variable: ' + process.env['SELENIUM_PROMISE_MANAGER']);
1042+
} else if (opt_skipLog !== SKIP_LOG) {
1043+
FLOW_LOG.warning(() => {
1044+
let e =
1045+
captureStackTrace(
1046+
'ManagedPromiseError',
1047+
'Creating a new managed Promise. This call will fail when the'
1048+
+ ' promise manager is disabled',
1049+
ManagedPromise)
1050+
return e.stack;
1051+
});
10351052
}
1053+
10361054
getUid(this);
10371055

10381056
/** @private {!ControlFlow} */
@@ -1432,15 +1450,19 @@ class Deferred {
14321450
/**
14331451
* @param {ControlFlow=} opt_flow The control flow this instance was
14341452
* created under. This should only be provided during unit tests.
1453+
* @param {?=} opt_skipLog An internal parameter used to skip logging the
1454+
* creation of this promise. This parameter has no effect unless it is
1455+
* strictly equal to an internal symbol. In other words, this parameter
1456+
* is always ignored for external code.
14351457
*/
1436-
constructor(opt_flow) {
1458+
constructor(opt_flow, opt_skipLog) {
14371459
var fulfill, reject;
14381460

14391461
/** @type {!ManagedPromise<T>} */
14401462
this.promise = new ManagedPromise(function(f, r) {
14411463
fulfill = f;
14421464
reject = r;
1443-
}, opt_flow);
1465+
}, opt_flow, opt_skipLog);
14441466

14451467
var self = this;
14461468
var checkNotSelf = function(value) {
@@ -1563,9 +1585,17 @@ function defer() {
15631585
function fulfilled(opt_value) {
15641586
let ctor = usePromiseManager() ? ManagedPromise : NativePromise;
15651587
if (opt_value instanceof ctor) {
1566-
return /** @type {!Thenable<T>} */(opt_value);
1588+
return /** @type {!Thenable} */(opt_value);
1589+
}
1590+
1591+
if (usePromiseManager()) {
1592+
// We can skip logging warnings about creating a managed promise because
1593+
// this function will automatically switch to use a native promise when
1594+
// the promise manager is disabled.
1595+
return new ManagedPromise(
1596+
resolve => resolve(opt_value), undefined, SKIP_LOG);
15671597
}
1568-
return ctor.resolve(opt_value);
1598+
return NativePromise.resolve(opt_value);
15691599
}
15701600

15711601

@@ -1582,7 +1612,11 @@ function fulfilled(opt_value) {
15821612
*/
15831613
function rejected(opt_reason) {
15841614
if (usePromiseManager()) {
1585-
return ManagedPromise.reject(opt_reason);
1615+
// We can skip logging warnings about creating a managed promise because
1616+
// this function will automatically switch to use a native promise when
1617+
// the promise manager is disabled.
1618+
return new ManagedPromise(
1619+
(_, reject) => reject(opt_reason), undefined, SKIP_LOG);
15861620
}
15871621
return NativePromise.reject(opt_reason);
15881622
}
@@ -2444,23 +2478,39 @@ class ControlFlow extends events.EventEmitter {
24442478
}
24452479

24462480
if (!this.hold_) {
2447-
var holdIntervalMs = 2147483647; // 2^31-1; max timer length for Node.js
2481+
let holdIntervalMs = 2147483647; // 2^31-1; max timer length for Node.js
24482482
this.hold_ = setInterval(function() {}, holdIntervalMs);
24492483
}
24502484

2451-
var task = new Task(
2485+
let task = new Task(
24522486
this, fn, opt_description || '<anonymous>',
2453-
{name: 'Task', top: ControlFlow.prototype.execute});
2487+
{name: 'Task', top: ControlFlow.prototype.execute},
2488+
true);
2489+
2490+
let q = this.getActiveQueue_();
2491+
2492+
for (let i = q.tasks_.length; i > 0; i--) {
2493+
let previousTask = q.tasks_[i - 1];
2494+
if (previousTask.userTask_) {
2495+
FLOW_LOG.warning(() => {
2496+
return `Detected scheduling of an unchained task.
2497+
When the promise manager is disabled, unchained tasks will not wait for
2498+
previously scheduled tasks to finish before starting to execute.
2499+
New task: ${task.promise.stack_.stack}
2500+
Previous task: ${previousTask.promise.stack_.stack}`.split(/\n/).join('\n ');
2501+
});
2502+
break;
2503+
}
2504+
}
24542505

2455-
var q = this.getActiveQueue_();
24562506
q.enqueue(task);
24572507
this.emit(ControlFlow.EventType.SCHEDULE_TASK, task.description);
24582508
return task.promise;
24592509
}
24602510

24612511
/** @override */
24622512
promise(resolver) {
2463-
return new ManagedPromise(resolver, this);
2513+
return new ManagedPromise(resolver, this, SKIP_LOG);
24642514
}
24652515

24662516
/** @override */
@@ -2729,9 +2779,11 @@ class Task extends Deferred {
27292779
* @param {string} description A description of the task for debugging.
27302780
* @param {{name: string, top: !Function}=} opt_stackOptions Options to use
27312781
* when capturing the stacktrace for when this task was created.
2782+
* @param {boolean=} opt_isUserTask Whether this task was explicitly scheduled
2783+
* by the use of the promise manager.
27322784
*/
2733-
constructor(flow, fn, description, opt_stackOptions) {
2734-
super(flow);
2785+
constructor(flow, fn, description, opt_stackOptions, opt_isUserTask) {
2786+
super(flow, SKIP_LOG);
27352787
getUid(this);
27362788

27372789
/** @type {function(): (T|!ManagedPromise<T>)} */
@@ -2743,6 +2795,9 @@ class Task extends Deferred {
27432795
/** @type {TaskQueue} */
27442796
this.queue = null;
27452797

2798+
/** @private @const {boolean} */
2799+
this.userTask_ = !!opt_isUserTask;
2800+
27462801
/**
27472802
* Whether this task is considered block. A blocked task may be registered
27482803
* in a task queue, but will be dropped if it is still blocked when it

0 commit comments

Comments
 (0)