ads-client-subscribe-twincat-logger.js

/*
Example how to subscribe and handle TwinCAT Logger data
https://jisotalo.github.io

Copyright (c) Jussi Isotalo <[email protected]>

Permission is hereby granted, free of charge, to any person obtaining a copy
of this software and associated documentation files (the "Software"), to deal
in the Software without restriction, including without limitation the rights
to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
copies of the Software, and to permit persons to whom the Software is
furnished to do so, subject to the following conditions:
The above copyright notice and this permission notice shall be included in all
copies or substantial portions of the Software.

THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
SOFTWARE.
*/
const ads = require('ads-client');
const long = require('long'); //Required to handle FILETIME

const client = new ads.Client({
  targetAmsNetId: 'localhost',
  targetAdsPort: 100,
  bareClient: true
});

/**
 * Converts msgType to array of message types
 * @param {number} msgTypeMask 
 * @returns 
 */
const convertMsgType = (msgTypeMask) => {
  let strs = [];

  if ((msgTypeMask & 0x1) == 0x1)
    strs.push('hint')
  if ((msgTypeMask & 0x2) == 0x2)
    strs.push('warning')
  if ((msgTypeMask & 0x4) == 0x4)
    strs.push('error')
  if ((msgTypeMask & 0x10) == 0x10)
    strs.push('log')
  if ((msgTypeMask & 0x20) == 0x20)
    strs.push('msgbox')
  if ((msgTypeMask & 0x40) == 0x40)
    strs.push('resource')
  if ((msgTypeMask & 0x80) == 0x80)
    strs.push('string')

  return strs;
}

/**
 * Unpacks received TwinCAT Logger entry to object
 * @param {Buffer} data 
 * @returns 
 */
const unpackTwinCatLoggerEntry = (data) => {
  let pos = 0;
  const row = {};
  const _unknown = {};
  
  //0..7 - timestamp
  row.timestamp = new Date(new long(data.readUInt32LE(pos), data.readUInt32LE(pos + 4)).div(10000).sub(11644473600000).toNumber());
  pos += 8;

  //8 - message type
  row.msgTypeMask = data.readUint8(pos);
  row.msgTypes = convertMsgType(row.msgTypeMask);
  pos += 1;

  //9 - unknown byte
  _unknown.byte_9 = data.readUint8(pos);
  pos += 1;

  //10 - unknown byte
  _unknown.byte_10 = data.readUint8(pos);
  pos += 1;

  //11 - unknown byte
  _unknown.byte_11 = data.readUint8(pos);
  pos += 1;

  //12..13 - sender ADS port
  row.senderAdsPort = data.readUint16LE(pos);
  pos += 2;

  //14 - unknown byte
  _unknown.byte_14 = data.readUint8(pos);
  pos += 1;

  //15 - unknown byte
  _unknown.byte_15 = data.readUint8(pos);
  pos += 1;

  //16..n - sender and payload string
  //There are also few bytes of unknown data between sender and msg, not handled here
  let str = data.slice(pos).toString().slice(0, -1);

  //Sender is from start of string until \0
  row.sender = str.substr(0, str.indexOf("\0"));

  //Message is from end until \0
  row.msg = str.substr(str.lastIndexOf("\0") + 1);

  //Uncomment to add unknown bytes to object
  //row._unknown = _unknown;

  //Uncomment to add raw data to object
  //row._raw = data;

  return row;
}

//Following can be used to test
//unpackTwinCatLoggerEntry(Buffer.from('50d8be9f72d6d80101000000102700005477696e4341542053797374656d00002000000054635254696d652053657276657220737461727465643a2054635254696d652e00', 'hex'));

client.connect()
  .then(async res => {
    console.log(`Connected to the ${res.targetAmsNetId}`);
    console.log(`Router assigned us AmsNetId ${res.localAmsNetId} and port ${res.localAdsPort}`);

    await client.subscribeRaw(1, 0xffff, 1024, data => {
      const entry = unpackTwinCatLoggerEntry(data.value);

      console.log(entry);
      
    }, 0, false); //Note: cyclic and 0ms cycle time

    console.log('Subscribed');    
  })
  .catch(err => {
    console.log('Something failed:', err)
  })

Example output:

Connected to the 127.0.0.1.1.1
Router assigned us AmsNetId 192.168.5.131.1.1 and port 33805
Subscribed
{
  timestamp: 2022-10-02T18:51:05.496Z,
  msgTypeMask: 1,
  msgTypes: [ 'hint' ],
  senderAdsPort: 10000,
  sender: 'TwinCAT System',
  msg: 'TwinCAT System Restart initiated from AmsNetId: 192.168.5.131.1.1 port 33195.'
}
{
  timestamp: 2022-10-02T18:51:05.525Z,
  msgTypeMask: 1,
  msgTypes: [ 'hint' ],
  senderAdsPort: 10000,
  sender: 'TwinCAT System',
  msg: 'Saving configuration of COM server TcEventLogger !'
}
{
  timestamp: 2022-10-02T18:51:06.252Z,
  msgTypeMask: 1,
  msgTypes: [ 'hint' ],
  senderAdsPort: 10000,
  sender: 'TwinCAT System',
  msg: 'Shutting down COM Server TcEventLogger !'
}

It seems some messages are UTF-8 encoded, indicated by bit 12.

As an experiment, I gave Claude the hex-encoded raw message below, and it came up with a mostly working decoder — not dissimilar from yours. (I suspect the crawler at Anthropic has been reading your blog 😉)

80669261317bdb01120800000a00000054434f4d20536572766572000000000039000000446576696365203320284574686572434154293a204672616d65206d69737365642031302074696d657320286672616d65206e6f2e2030290000

Here's the code (with a few minor fixes from my side):

/**
 * Inspired by https://gist.github.com/jisotalo/80b01d590666dc19b228c732353820a1,
 * UTF-8 parsing enabled with help from Claude Sonnet.
 *
 * @see https://jisotalo.fi/subscribing-to-twincat-logger-in-nodejs/
 */

type MessageType = 'hint' | 'warning' | 'error' | 'log' | 'msgbox' | 'resource' | 'string'

interface TwinCATLogEntry {
  timestamp: Date
  msgTypeMask: number
  msgTypes: MessageType[]
  senderAdsPort: number
  sender: string
  msg: string
}

// Bit flags for message types
enum MessageTypeMask {
  HINT = 0x01,
  WARN = 0x02,
  ERROR = 0x04,
  LOG = 0x10,
  MSGBOX = 0x20,
  RESOURCE = 0x40,
  STRING = 0x80,
  UTF8 = 0x1000, // Bit 12 indicates UTF-8 encoding
}

function decodeString(buffer: Buffer, startPos: number, isUtf8: boolean): { text: string; endPos: number } {
  let endPos = startPos
  while (buffer[endPos] !== 0 && endPos < buffer.length) endPos++

  const text = isUtf8 ? buffer.toString('utf8', startPos, endPos) : buffer.toString('latin1', startPos, endPos)

  return { text, endPos }
}

export function decodeTwinCATMessage(buffer: Buffer): TwinCATLogEntry {
  // Read timestamp (first 8 bytes) - Windows FILETIME format
  const fileTime = buffer.readBigInt64LE(0)
  // Convert Windows FILETIME to Unix timestamp (subtract Windows epoch and convert to milliseconds)
  const unixTime = Number((fileTime - BigInt(116444736000000000)) / BigInt(10000))
  const timestamp = new Date(unixTime)

  // Read message type mask (4 bytes)
  const msgTypeMask = buffer.readUInt32LE(8)

  // Check if strings are UTF-8 encoded
  const isUtf8 = !!(msgTypeMask & MessageTypeMask.UTF8)

  // Decode message types based on mask
  const msgTypes: MessageType[] = []
  if (msgTypeMask & MessageTypeMask.HINT) msgTypes.push('hint')
  if (msgTypeMask & MessageTypeMask.WARN) msgTypes.push('warning')
  if (msgTypeMask & MessageTypeMask.ERROR) msgTypes.push('error')
  if (msgTypeMask & MessageTypeMask.LOG) msgTypes.push('log')
  if (msgTypeMask & MessageTypeMask.MSGBOX) msgTypes.push('msgbox')
  if (msgTypeMask & MessageTypeMask.RESOURCE) msgTypes.push('resource')
  if (msgTypeMask & MessageTypeMask.STRING) msgTypes.push('string')

  // Read ADS port (4 bytes)
  const senderAdsPort = buffer.readUInt32LE(12)

  // Read sender string (null-terminated)
  const { text: sender, endPos: senderEndPos } = decodeString(buffer, 16, isUtf8)

  // Skip padding zeros and read message length (4 bytes)
  let pos = senderEndPos + 1
  while (buffer[pos] === 0 && pos < buffer.length) pos++
  pos += 4

  // Read message
  const { text: msg } = decodeString(buffer, pos, isUtf8)

  return {
    timestamp,
    msgTypeMask,
    msgTypes,
    senderAdsPort,
    sender,
    msg,
  }
}

And some tests I wrote:

import { describe, expect, it } from 'bun:test'
import { decodeTwinCATMessage } from '../src/services/plc/TwinCATLog'

describe('TwinCAT log monitor', () => {
  it('can unpack System Restart message', () => {
    const hex =
      '70cb5da5437ddb01910000001027000054635379735372760000000000000000490000005477696e4341542053797374656d205265737461727420696e697469617465642066726f6d20416d734e657449643a2031302e332e302e33312e312e3120706f72742033393035302e00'
    const buffer = Buffer.from(hex, 'hex')
    const decoded = decodeTwinCATMessage(buffer)
    expect(decoded).toEqual({
      msg: 'TwinCAT System Restart initiated from AmsNetId: 10.3.0.31.1.1 port 39050.',
      msgTypeMask: 145,
      timestamp: new Date(Date.parse('2025-02-12T11:45:42.823Z')),
      msgTypes: ['hint', 'log', 'string'],
      sender: 'TcSysSrv',
      senderAdsPort: 10000,
    })
  })

  it('can unpack TCOM Server message', () => {
    const hex = '80669261317bdb01120800000a00000054434f4d20536572766572000000000039000000446576696365203320284574686572434154293a204672616d65206d69737365642031302074696d657320286672616d65206e6f2e2030290000'
    const buffer = Buffer.from(hex, 'hex')
    const decoded = decodeTwinCATMessage(buffer)
    expect(decoded).toEqual({
      msg: 'Device 3 (EtherCAT): Frame missed 10 times (frame no. 0)',
      msgTypeMask: 2066,
      msgTypes: ['warning', 'log'],
      sender: 'TCOM Server',
      senderAdsPort: 10,
      timestamp: new Date(Date.parse('2025-02-09T20:29:55.816Z')),
    })
  })

})

Nice @crishoj!

That is an excellent piece of code. Easy way to add logging of system events etc.