TypeError: Cannot destructure property 'message' of 'tracker.fetch(...)' as it is null

[BryanHunt]

ldapjs 3.0.2

I'm getting an occasional crash with the following error. I do have an error handler registered with the client, so I think this is a case that is not covered.

/app/node_modules/ldapjs/lib/client/client.js:884
      const { message: trackedMessage, callback } = tracker.fetch(message.messageId)
                       ^
TypeError: Cannot destructure property 'message' of 'tracker.fetch(...)' as it is null.
    at Parser.onMessage (/app/node_modules/ldapjs/lib/client/client.js:884:24)
    at Parser.emit (node:events:513:28)
    at Parser.write (/app/node_modules/ldapjs/lib/messages/parser.js:135:8)
    at TLSSocket.onData (/app/node_modules/ldapjs/lib/client/client.js:875:22)
    at TLSSocket.emit (node:events:513:28)
    at addChunk (node:internal/streams/readable:315:12)
    at readableAddChunk (node:internal/streams/readable:289:9)
    at TLSSocket.Readable.push (node:internal/streams/readable:228:10)
    at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23)
    at TLSWrap.callbackTrampoline (node:internal/async_hooks:130:17)

[jsumners]

A minimal reproduction will be needed to provide support on this.

[BryanHunt]

This problem occurs maybe once a day out of 5 running instances. Reproduction is going to be impossible. My recommendation is to add a check for the case described in the error message and emit an error back to the client. That way, I can handle the error in my code rather than the application crash.

[BryanHunt]

So you are fine with applications crashing that use your code?

[jsumners]

I asked for more information. You declined to give it. I cannot diagnose a problem without a reproduction. There should be zero instances that a message is unavailable. So there is most likely some issue in whatever ldap conversation that resulted in the report.

I am quite willing to collaborate on a diagnosis and solution if you are, but we'll need a reproduction.

[janiago]

I have met the same issue in my production ENV. I can try to catch it as "uncaughtException" on process level, but it's not a long term solution. Hope the issue can be solved, otherwise we have to change our LDAP solution.
Thanks!

[benzhuo]

In client/message/tracker/index.js line 91
function ** tracker.fetch ** returns null if neither tracked==true nor abandonedMsg==true
which will cause line 884 in client.js crash
const { message: trackedMessage, callback } = tracker.fetch(message.messageId)

TypeError: Cannot destructure property 'message' of 'tracker.fetch(...)' as it is null.

---

tracker.fetch = function fetchMessage (msgID) {
    const tracked = messages.get(msgID)
    if (tracked) {
      purgeAbandoned(msgID, abandoned)
      return tracked
      return null
    }

    // We sent an abandon request but the server either wasn't able to process
    // it or has not received it yet. Therefore, we received a response for the
    // abandoned message. So we must return the abandoned message's callback
    // to be processed normally.
    const abandonedMsg = abandoned.get(msgID)
    if (abandonedMsg) {
      return { message: abandonedMsg, callback: abandonedMsg.cb }
    }

    return null
  }

[jsumners]

Thank you for the diagnosis @benzhuo. It at least gives us something to go on.

It looks like the difference is the following:

v2.x:

node-ldapjs/lib/client/client.js

Lines 878 to 889 in 92dfc80

	// The "router"
	tracker.parser.on('message', function onMessage (message) {
	message.connection = self._socket
	const callback = tracker.fetch(message.messageID)
	if (!callback) {
	log.error({ message: message.json }, 'unsolicited message')
	return false
	}
	return callback(message)
	})

v3:

node-ldapjs/lib/client/client.js

Lines 878 to 920 in f289008

	// The "router"
	//
	// This is invoked after the incoming BER has been parsed into a JavaScript
	// object.
	tracker.parser.on('message', function onMessage (message) {
	message.connection = self._socket
	const { message: trackedMessage, callback } = tracker.fetch(message.messageId)
	if (!callback) {
	log.error({ message: message.pojo }, 'unsolicited message')
	return false
	}
	// Some message types have narrower implementations and require extra
	// parsing to be complete. In particular, ExtensionRequest messages will
	// return responses that do not identify the request that generated them.
	// Therefore, we have to match the response to the request and handle
	// the extra processing accordingly.
	switch (trackedMessage.type) {
	case 'ExtensionRequest': {
	const extensionType = ExtendedRequest.recognizedOIDs().lookupName(trackedMessage.requestName)
	switch (extensionType) {
	case 'PASSWORD_MODIFY': {
	message = messages.PasswordModifyResponse.fromResponse(message)
	break
	}
	case 'WHO_AM_I': {
	message = messages.WhoAmIResponse.fromResponse(message)
	break
	}
	default:
	}
	break
	}
	default:
	}
	return callback(message)
	})

The short of it is: we neglected to recognize that tracker.fetch can return null under some (still unknown) circumstance(s). I really wish we could figure out what those circumstances are, but I think we can introduce some logging here to give us a clue.

[michelevince]

Hello!
I have experienced the same problem and I may have found a way to reproduce it.

In my case this error happens every time the ldap server takes more time than "timeout" configuration parameter to answer. I configured it to 10000 ms. I'm trying always a search action.

My logs are:

searchRequest:  {"messageId":2,"protocolOp":99,"type":"SearchRequest","baseObject":"dc=example,dc=com","scope":"subtree","derefAliases":0,"sizeLimit":0,"timeLimit":10,"typesOnly":false,"filter":"(cn=aaaaa)","attributes":["*"],"controls":[]}


error: request timeout (client interrupt)
TimeoutError: request timeout (client interrupt)
    at Timeout.onRequestTimeout (.../app/node_modules/ldapjs/lib/client/client.js:1277:10)
    at listOnTimeout (node:internal/timers:564:17)
    at process.processTimers (node:internal/timers:507:7) {
  lde_message: 'request timeout (client interrupt)',
  lde_dn: null
}


.../app/node_modules/ldapjs/lib/client/client.js:884
      const { message: trackedMessage, callback } = tracker.fetch(message.messageId)
                       ^

TypeError: Cannot destructure property 'message' of 'tracker.fetch(...)' as it is null.
    at Parser.onMessage (.../app/node_modules/ldapjs/lib/client/client.js:884:24)
    at Parser.emit (node:events:513:28)
    at Parser.write (.../app/node_modules/ldapjs/lib/messages/parser.js:135:8)
    at Socket.onData (.../app/node_modules/ldapjs/lib/client/client.js:875:22)
    at Socket.emit (node:events:513:28)
    at addChunk (node:internal/streams/readable:324:12)
    at readableAddChunk (node:internal/streams/readable:297:9)
    at Readable.push (node:internal/streams/readable:234:10)
    at TCP.onStreamRead (node:internal/stream_base_commons:190:23)

Node.js v18.9.0

[benzhuo]

Hi Jsumners,
When will a new version is available? is there a plan?

[jsumners]

Please recognize that we are not in the same parts of the world and that while you are awake I am asleep. I also need to take time to verify that proposed changes cover the issue correctly, and my current priority is finding gainful employment.

[benzhuo]

I understand, hope this can be released as soon. good luck, there will be bread.

[jsumners]

https://github.com/ldapjs/node-ldapjs/releases/tag/v3.0.3

[benzhuo]

Thanks, jsumner