Fix what the product-owner pass found in the README, and log an unmergeable receipt (#94)

* Log an unmergeable receipt and correct the README where it overclaims

* Name decodeMessage's arguments and pin the hook's keepalive and unbind

* Let the test name carry what its comment restated

README.md

@@ -294,6 +294,13 @@ A hook that throws or rejects reaches `sessionError`, and nothing else is writte
 the library cannot tell a hook that failed before answering from one that failed after, and a second
 response on the peer's sequence number would be worse than none. The peer's own response timeout
 settles it, so a hook that must reach a decision either way makes that decision itself.
+`authenticate` fails the same way, leaving the bind itself unanswered.
+
+`enquire_link` and `unbind` reach the hook too, where failing costs more than the one request a
+response timeout settles: an unanswered `enquire_link` has the peer drop the link at its own idle
+timer, and an unanswered `unbind` skips the close this end would have run on it. Guard on the
+command name, as the example above does, and a hook that fails takes nothing but its own request
+with it.
 
 A `Session` you construct yourself (see [Bind direction](#bind-direction)) takes the same hook as a
 session option, and handles a failing one the same way; it is also where a peer's bind gets accepted,
@@ -368,6 +375,9 @@ rest:
 - **Everything else**: the session or the socket failing, and a hook or listener that threw or, if it
   was `async`, rejected.
 
+The last two are both a plain `Error`, told apart from each other by their message text alone, so
+the example below alerts on a lost concatenated message as well as on a session that failed.
+
 ```javascript
 import { PduRefusedError } from '@larvit/smpp';
 
@@ -381,7 +391,7 @@ session.on('sessionError', err => {
 		return;
 	}
 
-	log.error('the session failed', { message: err.message });
+	log.error('a session failure or lost traffic', { message: err.message });
 });
 ```
 
@@ -437,7 +447,7 @@ TypeScript users can import `SmppLog` to have the compiler check one.
 | `close` | The session is over, because nothing will bring the link back. Fires once, whether you closed it or the link failed for good. |
 | `disconnected` | The link dropped and the reconnect loop will retry it. Do not open a replacement client here — the session you hold comes back on its own, and `reconnected` says when. Fires again for each attempt that reconnects and then fails, so it is not one-to-one with `reconnected`. |
 | `reconnected` | The client re-bound after a drop. |
-| `sessionError` | Something failed on a live session, including a hook or listener that threw or, if it was `async`, rejected. Fires for each PDU the codec refused as well, carrying a `PduRefusedError` while the link carries on: a refused request is answered with the status SMPP names, and a refused response is answered with nothing and settles the request it named as `unanswered`. [Errors](#errors) tells its three kinds apart. |
+| `sessionError` | Something failed on a live session, including a hook or listener that threw or, if it was `async`, rejected. Fires for each PDU the codec refused as well, carrying a `PduRefusedError` while the link carries on: a refused request is answered with the status SMPP names, and a refused response is answered with nothing and settles the request it named as `unanswered`. [Errors](#errors) names its three kinds, of which `PduRefusedError` separates one. |
 | `data` | Raw bytes arrived on the socket. |
 | `incomingPdu` | A complete PDU arrived, as a buffer. |
 | `incomingPduObj` | The same PDU, parsed into an object. |
@@ -451,7 +461,9 @@ every `sms` still in the application's hands, so a peer whose `submit_sm` is bei
 answered rather than left to re-send it. That wait ends when `sendResp()` puts the response on the
 wire — or, for a message whose segments were answered as they arrived, when it is called at all —
 or when every listener that took the message has failed; answering its PDUs through
-`sendReturn()` instead leaves the wait running until it gives up. `sendDlr()` is the one send the
+`sendReturn()` instead leaves the wait running until it gives up. A session holds at most 1000
+unanswered messages, five minutes each; what falls out of either bound is dropped with a warning on
+the log and waited for no longer. Neither bound is an option. `sendDlr()` is the one send the
 refusal lets past, and it catches the wait when issued straight after `sendResp()`; await anything in
 between and it races the shutdown like any other send. `close({ signal })` takes an `AbortSignal`
 that cuts the wait short; `unbind()` takes none, and waits a further
@@ -529,7 +541,9 @@ if (isCommand(pduObj, 'submit_sm')) {
 `params.short_message` is decoded with the PDU's own `data_coding`; `shortMessageOctets` is that
 same field exactly as it arrived. Neither holds the body of a PDU that carried it in the
 `message_payload` TLV instead, which a `data_sm` always does — `messageOctets(pduObj)` is the one
-answer to which of the two the peer used. `concatOf(pduObj)` is the same for concatenation: the
+answer to which of the two the peer used, and gives back the octets undecoded:
+`decodeMessage(octets, pduObj.params.data_coding, pduObj.params.esm_class)` turns them into text and
+hands back the UDH where the PDU carries one. `concatOf(pduObj)` is the same for concatenation: the
 `part`, `total` and `reference` a PDU declares, and the `spelling` — `'udh'` or `'sar'` — that
 carried them, or `undefined` where the PDU is a whole message.
 
@@ -609,6 +623,11 @@ have worked around any of these, remove the workaround:
   and `sar_segment_seqnum` TLVs rather than by a user data header was never reassembled, so each
   segment arrived as its own message. Both spellings reassemble now.
 - Short or malformed PDUs threw out of the codec instead of being reported as a parse failure.
+- A PDU whose optional parameters do not end exactly on `command_length` is refused with
+  `ESME_RINVTLVSTREAM` and dropped, where 0.4.0 kept the TLVs it had read and ignored the octets
+  left over — which loses the `receipted_message_id` that makes a receipt a receipt. The refusal
+  reaches `sessionError` as a `PduRefusedError` with `reason` `tlvs`, which is what to match on
+  where a peer's traffic goes missing.
 - Binds now declare `interface_version` 0x34. 0.4.0 declared 0x00, which tells the SMSC the ESME
   speaks SMPP 3.3 or earlier — and a spec-following SMSC then withholds every optional parameter,
   including the TLVs delivery receipts are carried in.

src/dlr-merger.ts

@@ -114,7 +114,11 @@ export class DlrMerger {
 		const { base, part: number } = numbering;
 		const group = this.groups.get(base);
 
-		if (!group) return undefined;
+		if (!group) {
+			this.log.debug('dlrMerger - receipt names no message being merged', { base, smsId: dlr.smsId });
+
+			return undefined;
+		}
 
 		if (!group.expected.has(number)) return undefined;
 

test/readme.test.ts

@@ -335,7 +335,7 @@ describe('README: Errors', () => {
 				return;
 			}
 
-			log.error('the session failed', { message: err.message });
+			log.error('a session failure or lost traffic', { message: err.message });
 		});
 
 		const reported = once<Error>(resolve => { session.on('sessionError', resolve); });

test/session.test.ts

@@ -2260,7 +2260,7 @@ describe('the server\'s onRequest hook', () => {
 		assert.deepEqual(seen, [], 'a bind, and everything a peer sends before one, is never the hook\'s');
 	});
 
-	test('passes a request the hook declines through to the sms event', async t => {
+	test('passes a declined request to the sms event, and offers the keepalive and the unbind too', async t => {
 		const seen: string[] = [];
 		const smpp = await startServer(t, {
 			onRequest: (_bound, pduObj) => { seen.push(pduObj.cmdName); return false; },
@@ -2278,11 +2278,14 @@ describe('the server\'s onRequest hook', () => {
 		const answered = await submitTo(session, '46709771337', 'declined by the hook');
 		const sms = await incoming;
 
+		await session.send({ cmdName: 'enquire_link' });
+		await session.unbind();
+
 		assert.ok(answered.pduObj);
 		assert.equal(answered.pduObj.cmdStatus, 'ESME_ROK');
 		assert.equal(paramText(answered.pduObj.params.message_id), answeredId);
 		assert.equal(sms.message, 'declined by the hook');
-		assert.deepEqual(seen, ['submit_sm']);
+		assert.deepEqual(seen, ['submit_sm', 'enquire_link', 'unbind']);
 	});
 
 	test('reports a hook that throws and answers nothing for it', async t => {
@@ -2447,9 +2450,9 @@ describe('merged delivery report bounds', () => {
 		};
 	}
 
-	function merger(options: { max?: number; now?: () => number } = {}): DlrMerger {
+	function merger(options: { log?: SmppLog; max?: number; now?: () => number } = {}): DlrMerger {
 		return new DlrMerger({
-			log: silentLog,
+			log: options.log ?? silentLog,
 			max: options.max ?? 10,
 			now: options.now ?? (() => 0),
 			timeout: 60,
@@ -2471,6 +2474,26 @@ describe('merged delivery report bounds', () => {
 		assert.equal(dlrMerger.size, 0);
 	});
 
+	// An id answered in one notation and reported in another merges nothing and reports nothing.
+	test('logs the receipt of a base no send is waiting on, and stays quiet for a single-part id', () => {
+		const debugged: Record<string, boolean | number | string>[] = [];
+		const dlrMerger = merger({
+			log: { ...silentLog, debug: (msg, metadata) => { debugged.push({ msg, ...metadata }); } },
+		});
+
+		dlrMerger.expect(['1a2b-1', '1a2b-2']);
+
+		assert.equal(dlrMerger.collect(receipt('6699-1')), undefined);
+		assert.deepEqual(debugged, [{
+			base: '6699',
+			msg: 'dlrMerger - receipt names no message being merged',
+			smsId: '6699-1',
+		}]);
+
+		assert.equal(dlrMerger.collect(receipt('019878e0e3d97b2c9d8a4f6b1c0e5a73')), undefined);
+		assert.equal(debugged.length, 1, 'a single-part receipt was never expected to merge');
+	});
+
 	// Telesign answers only the first segment of a concatenated submit with a message id.
 	test('arms nothing for a send whose ids do not number one message', () => {
 		const dlrMerger = merger();