DriverKit IOUserSerial Driver

Hello everyone. After a lot of research and some tests from various sources, I have actually built a small SerialDriverKit IOUserSerial driver. Unfortunately, the documentation on the official sites is tight-lipped and very thin. At least I have a running driver instance. Now my request and question: Can anyone give me a tip on how to get the data from the serial client? I have already called IOUserSerial::ConnectQueues(...) in the IOUserSerial::Start() method and I got the IOMemoryDescriptors for interrupt, RX and TX to my driver instance. I tried to get access to the memory in the method IOUserSerial::TxDataAvailable() with IOMemoryDescriptor::CreateMapping(...).

Unfortunately, no data is coming in. It's always 0x00. Here is the OS log:

kernel: (org.eof.tools.VSPDriver.dext) <private> kernel: (org.eof.tools.VSPDriver.dext) [VSPDriver] init called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] constructor called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriver] start called. kernel: (org.eof.tools.VSPDriver.dext) IOUserSerial::<private>: 40 0x600000da4058 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] Start called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] Connect INT/RX/TX buffer. kernel: (org.eof.tools.VSPDriver.dext) IOUserSerial::<private>: 59 0x600000da4058 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] prepare TCP socket. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriver] driver started successfully. kernel: DK: VSPDriver-0x100000753::start(IOUserResources-0x100000116) ok ... ... some client serial setup stuff ... kernel: (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 ==>0 kernel: (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 <== kernel: (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 locklevel = 1 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriver] HwResetFIFO called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] HwResetFIFO called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] HwResetFIFO: tx=0 rx=1 kernel: (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 ==>0 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriver] TxDataAvailable called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable called. kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: address=0x104c22000 length=16384 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: debug TX buffer kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00 kernel: (org.eof.tools.VSPDriver.dext) [VSPDriverPrivate] TxDataAvailable: TX> 0x00

Answered by DTS Engineer in 823975022

I’m gonna ask Kevin to wade in here, because he knows the DriverKit side of this much better than I do.

I'm here...

SO, let me start with some more "foundational" guidance. Inside the DriverKit.iig file, you'll find methods declared in two different ways:

  • Standard declaration:
	virtual void            RxDataAvailable();
  • "LOCAL" declaration:
	virtual void            RxFreeSpaceAvailable() LOCAL;

The "LOCAL" keyword is critical here. As the documentation puts it:

"Tells the system that the method runs locally in the driver extension's process space."

AND:

"DriverKit adds this macro to methods that must run locally in your driver extension. A method tagged with this macro may still be called by a remote process such as the kernel. Don't add this macro to your own methods."

Unfortunately, the phrase "may still be called..." is somewhat misleading, as what we really meant was "will be called...". That is, the entire reason a method is tagged with "LOCAL" is to inform you that we need to implement it because we WILL be calling it.

That leads back to here:

Can anyone give me a tip on how to get the data from the serial client?

"ConnectQueues" is declared "LOCAL", so the system is going to be calling it, not necessarily "you". The answer for virtual terminals ends up looking something like:

kern_return_t
IMPL(<your calls name>, ConnectQueues)
{
	IOReturn err = ConnectQueues(ifmd, rxqmd, txqmd, in_rxqmd, in_txqmd,
			in_rxqoffset, in_txqoffset, in_rxqlogsz, in_txqlogsz, SUPERDISPATCH));

	assert(err == kIOReturnSuccess);

	IOAddressSegment seg;

	assert(!(*ifmd)->GetAddressRange(&seg));
	<your pointer to the control struct> = (SerialPortInterface*)seg.address;

	//track any other memory you want a reference to....
	
	return kIOReturnSuccess;
}

My question is, how can I obtain the data in the method IOUserSerial::TxAvailable which has been called by the OS

The SerialPortInterface struct that you saved a pointer to in "ConnectQueues" has the data about exactly where the serial port is in the ring buffers the other memory descriptors manage.

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

Here my methods:

  1. Called from Start()...

IOReturn VSPDriverPrivate::ConnectDriverQueues() { IOReturn ret;

ret = m_driver->ConnectQueues(&m_itBuffer, &m_rxBuffer, &m_txBuffer, nullptr, nullptr, 0, 0, 8, 8);
if (ret != kIOReturnSuccess) {
    VSPLog(LOG_PREFIX, "ConnectQueues failed to allocate IF/RX/TX buffers.\n");
    return ret;
}
if (m_itBuffer == nullptr) {
    VSPLog(LOG_PREFIX, "Invalid interrupt buffer detected.\n");
    ret = kIOReturnInvalid;
    return ret;
}
if (m_rxBuffer == nullptr) {
    VSPLog(LOG_PREFIX, "Invalid RX buffer detected.\n");
    return kIOReturnInvalid;
}
if (m_txBuffer == nullptr) {
    VSPLog(LOG_PREFIX, "Invalid TX buffer detected.\n");
    return kIOReturnInvalid;
}

return kIOReturnSuccess;

}

  1. Inside TxDataAvailable()

IOReturn VSPDriverPrivate::TxDataAvailable() { IOReturn ret = kIOReturnSuccess; IOMemoryMap* map = nullptr;

VSPLog(LOG_PREFIX, "TxDataAvailable called.\n");

if (m_txBuffer == nullptr) {
    return kIOReturnBadArgument;
}

// Access memory of RX IOMemoryDescriptor
ret = m_txBuffer->CreateMapping(kIOMemoryMapReadOnly, 0, 0, 0, 0, &map);
if (ret != kIOReturnSuccess) {
    VSPLog(LOG_PREFIX, "TxDataAvailable: Failed to get memory map. code=%d\n", ret);
    return ret;
}

// Send data to ...
const char* buffer = reinterpret_cast<char*>(map->GetAddress());
const uint64_t size = map->GetLength();

VSPLog(LOG_PREFIX, "TxDataAvailable: address=0x%llx length=%llu\n", (uint64_t) buffer, size);
VSPLog(LOG_PREFIX, "TxDataAvailable: debug TX buffer\n");

// !! Debug ....
for (uint64_t i = 0; i < size && i < 16; i++) {
    VSPLog(LOG_PREFIX, "TxDataAvailable: TX> 0x%02x %c\n", buffer[i], buffer[i]);
}

// copy data to send into tx FIFO buffer
memcpy(m_fifo.tx.buffer, buffer, (size < m_fifo.tx.size ? size : m_fifo.tx.size));

// !! cleanup
OSSafeReleaseNULL(map);
return kIOReturnSuccess;
Written by eof-bg in 773636021
Can anyone give me a tip on how to get the data from the serial client?

Either I’m confused, or you are |-:

The serial family should expose your device as a standard BSD serial device, that is, as one or more nodes in /dev. So, if you’re not doing anything weird, and you just want to use the serial port as you would any other serial port on the system, you:

  • Find the name of the /dev node in the I/O registry.

  • Interact with that using standard BSD APIs, like open and read.

The very old SerialPortSample shows the basics of this.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Hello DTS Engineer, Yes, you're right, it's confusing. I forgot to mention the purpose of the extension. Sorry. The purpose of the extension is to:

  1. Use the DEXT to create nodes in '/dev' for serial ports (/dev/(tty&cu)-serail-xxxx.
  2. A user application (UI) should control the creation and linking of the serial ports.
  3. A measurement and control simulation (UI) should use the serial ports to simulate measurement and control devices 'at device level', while
  4. a second application uses the serial ports as a 'normal' interface to use the simulated measurement and control devices with different protocols .
  5. Final goal: It should be used to check whether the entire communication path works in a software framework.

In order to route the data from the user application (3) to the user application (4) and vice versa, I need to know exactly:

  1. How do I get the data from the IOMemoryDescriptor in the IOUserSerial instance?
  2. What is the mechanism for reading the incoming data reported by TxAvailable?

Thanks for the clarification.

So they way I’d approach this is to separate the data path and the control path. For the data path I’d use the serial port interface itself. You wrote:

Written by eof-bg in 823636022
the DEXT should do routing between the serial port /dev/tty-serial-A and /dev/tty-serial-B

Exactly that.

You can then use lower-bandwidth primitives (I/O Registry properties, simple user client messaging, and so on) for the control path.

This avoids the need for a high-bandwidth user client, getting you out of the business of memory mapping, I/O queues, and so on.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Hello Quinn "The Eskimo!" ;)

thank you for you response. Okay, I'm inside the DEXT 'kernel' space. You suggestion is my doing. Let us restart to my first question context. My question is, how can I obtain the data in the method IOUserSerial::TxAvailable which has been called by the OS even if the user client app send data like: echo 'Welcome' > /dev/cu.serial-100000A5E ??

Second question ist, can I write you an email too?

[ WHERE THE DATA 'Welcome' ? ] ------------------------

2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: TxDataAvailable called.
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: TxDataAvailable: Dump m_txqmd -------------
2025-02-05 08:33:00.866 Df kernel[0:e27] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 ==>0
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory called. md=0x600002c58d48
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory: CreateMapping.
2025-02-05 08:33:00.866 Df kernel[0:e27] (IOUserSerial) IOUserSerial::hwSendBreak: 1083 <==
2025-02-05 08:33:00.866 Df kernel[0:e27] (IOUserSerial) IOUserSerial::hwSendBreak: 1083 locklevel = 1
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory: GetAddress + GetLength.
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory: dump mapped buffer
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff=0x1025c8000 mapSize=16384
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[0]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[1]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[2]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[3]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[4]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[5]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[6]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[7]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[8]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[9]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[10]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[11]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[12]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[13]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[14]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: CopyMemory MAP> mapBuff[15]=0x00
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: TxFreeSpaceAvailable called.
2025-02-05 08:33:00.866 Df kernel[0:9d4f] () [VSPSerialPort]: RxDataAvailable called.

[ SNIPPET : END ] ---------------------------------------

This is the source of the CopyMemory method which is called from IOUserSerial::TxDataAvailable implementation in my driver extension:

// --------------------------------------------------------------------
// CopyMemory_Impl(IOMemoryDescriptor* md)
// ??? Called by TxDataAvailable() and here we get always 0x00 in MD
// ??? mapped buffer of the IOMemoryDescriptors m_txqmd
//
IOReturn IMPL(VSPSerialPort, CopyMemory)
{
    IOMemoryMap* map = nullptr;
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "CopyMemory called. md=0x%llx\n", (uint64_t)md);
    
    if (md == nullptr) {
        VSPLog(LOG_PREFIX, "copy_md_memory: Invalid memory descriptor (nullptr).\n");
        return kIOReturnBadArgument;
    }
    
    VSPLog(LOG_PREFIX, "CopyMemory: CreateMapping.\n");
    
    // Access memory of TX IOMemoryDescriptor
    uint64_t mapFlags =
    kIOMemoryMapGuardedDefault |
    kIOMemoryMapCacheModeDefault |
    kIOMemoryMapReadOnly;
    ret = md->CreateMapping(mapFlags, 0, 0, 0, 0, &map);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "copy_md_memory: Failed to get memory map. code=%d\n", ret);
        return ret;
    }
    
    VSPLog(LOG_PREFIX, "CopyMemory: GetAddress + GetLength.\n");
    
    // get mapped data...
    const uint64_t mapSize = map->GetLength();
    const uint8_t* mapBuff = (uint8_t*)(map->GetAddress());
    
    VSPLog(LOG_PREFIX, "CopyMemory: dump mapped buffer\n");
    VSPLog(LOG_PREFIX, "CopyMemory MAP> mapBuff=0x%llx mapSize=%llu\n", (uint64_t) mapBuff, mapSize);
    
    // !! Debug ....
    for (uint64_t i = 0; i < mapSize && i < 16; i++) {
        VSPLog(LOG_PREFIX, "CopyMemory MAP> mapBuff[%lld]=0x%02x %c\n", i, mapBuff[i], mapBuff[i]);
    }
    
    OSSafeReleaseNULL(map);
    return kIOReturnSuccess;
}

Best Regards.

Written by eof-bg in 823851022
inside the DEXT 'kernel' space … how can I obtain the data in the method

I’m gonna ask Kevin to wade in here, because he knows the DriverKit side of this much better than I do.

Written by eof-bg in 823851022
can I write you an email too?

There’s nothing stopping you (-: However, I’m not able to provide one-on-one support via email.

You could try opening a DTS code-level support request, but I don’t think that’ll fly in this case. DTS redirects most of those to the forums these days. That way all developers can benefit from our replies.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Yes, please ask Kevin :) Thx

Accepted Answer

I’m gonna ask Kevin to wade in here, because he knows the DriverKit side of this much better than I do.

I'm here...

SO, let me start with some more "foundational" guidance. Inside the DriverKit.iig file, you'll find methods declared in two different ways:

  • Standard declaration:
	virtual void            RxDataAvailable();
  • "LOCAL" declaration:
	virtual void            RxFreeSpaceAvailable() LOCAL;

The "LOCAL" keyword is critical here. As the documentation puts it:

"Tells the system that the method runs locally in the driver extension's process space."

AND:

"DriverKit adds this macro to methods that must run locally in your driver extension. A method tagged with this macro may still be called by a remote process such as the kernel. Don't add this macro to your own methods."

Unfortunately, the phrase "may still be called..." is somewhat misleading, as what we really meant was "will be called...". That is, the entire reason a method is tagged with "LOCAL" is to inform you that we need to implement it because we WILL be calling it.

That leads back to here:

Can anyone give me a tip on how to get the data from the serial client?

"ConnectQueues" is declared "LOCAL", so the system is going to be calling it, not necessarily "you". The answer for virtual terminals ends up looking something like:

kern_return_t
IMPL(<your calls name>, ConnectQueues)
{
	IOReturn err = ConnectQueues(ifmd, rxqmd, txqmd, in_rxqmd, in_txqmd,
			in_rxqoffset, in_txqoffset, in_rxqlogsz, in_txqlogsz, SUPERDISPATCH));

	assert(err == kIOReturnSuccess);

	IOAddressSegment seg;

	assert(!(*ifmd)->GetAddressRange(&seg));
	<your pointer to the control struct> = (SerialPortInterface*)seg.address;

	//track any other memory you want a reference to....
	
	return kIOReturnSuccess;
}

My question is, how can I obtain the data in the method IOUserSerial::TxAvailable which has been called by the OS

The SerialPortInterface struct that you saved a pointer to in "ConnectQueues" has the data about exactly where the serial port is in the ring buffers the other memory descriptors manage.

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

Hello Kevin, Thanks alot :-) Your comments gave me insight and a bright light into my darkest days :-) That helped me a lot. Also the LOCAL thing is an important aspect. A small note in context:

  1. The IOMemoryDescriptor txqmd and txqmd can be cast in IOBufferMemoryDescriptor. Perhaps the documentation should be adapted accordingly. Since it must really be assumed that the mechanism with GetAddressRange() is not available on txqmd and rxqmd (IOMemoryDescriptor does not have this method).
  1. Perhaps a small note in the documentation of the "ConnectQueues" method that is called at the beginning (presumably by open(/dev/....) or similar) by the OS. This creates more clarity for the reading developer.
  2. GetAddressRange() must be called in TxAvailable(), because in this context the buffer address of txqmd is only known and filled there.
  3. Here too, perhaps a note in the documentation of TxAvailable().

With these two notes, a different picture of how it works would emerge. I looked at apple-oss-distributions XNU on GitHub, unfortunately the SerialDriverKit was not represented there.

But, thank you for the help. I wish you all a good time. Best regards

  1. The IOMemoryDescriptor txqmd and txqmd can be cast in IOBufferMemoryDescriptor. Perhaps the documentation should be adapted accordingly. Since it must really be assumed that the mechanism with GetAddressRange() is not available on txqmd and rxqmd (IOMemoryDescriptor does not have this method).

Hmmm. That's a really weird one that I hadn't notice before. So, at a technical level, you're right that this works and that's because ConnectQueues(...) internal implementation either creates an IOBufferMemoryDescriptor from scratch (when the "in_" args are NULL) or takes the input IOMemoryDescriptor's... and then uses them to create an IOBufferMemoryDescriptor, which it returns. It's not REQUIRED to behave this way but, yes, that's what it does today.

Whether or not you rely on this is up to you. You could get the same result by creating a IOBufferMemoryDescriptor yourself from the IOMemoryDescriptor or by passing your own descriptor in. However, I would probably just OSDynamicCast to IOBufferMemoryDescriptor and then shutdown the entire DEXT if that cast fails. This is one of those cases where if it ever changed you should probably do a more detailed investigation to figure out what actually changed, instead of trying to code around it.

Perhaps a small note in the documentation of the "ConnectQueues" method that is called at the beginning (presumably by open(/dev/....) or similar) by the OS. This creates more clarity for the reading developer.

Please file a bug on this.

GetAddressRange() must be called in TxAvailable(), because in this context the buffer address of txqmd is only known and filled there.

No. The mapping here isn't dynamic- it's guaranteed to be stable for the life of the IOMemoryDescriptor. Those descriptor are destroyed in DisconnectQueues, however, you could retain them yourself if you wanted them to persist beyond them. Keep in mind that the role of IOMemoryDescriptor is to act as the object that bridge between the local address space (meaning, your processes memory), virtual memory (meaning, the system wide representation of a particular "thing"), and true physical memory (meaning, the actual address you'd push on to a PCI bus). A typical use for that descriptor would be to wire it, then pass it to a PCI card. At that point, that address is as stable as it gets.

FYI, what "GetAddressRange" actually does is call CreateMapping once (the first time it's called) to map the address, then return that address for all future calls.

Here too, perhaps a note in the documentation of TxAvailable().

Please file a bug on this.

With these two notes, a different picture of how it works would emerge. I looked at apple-oss-distributions XNU on GitHub, unfortunately the SerialDriverKit was not represented there.

I'd strongly encourage you to file bugs asking for DriverKit (and the various families) to be open sourced. I fully understand how helpful that would be and the best thing you can do to encourage that is filing bugs asking for it to happen.

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

Ah okay, yes I should file bugs. Well, a question about the step after receiving TX data. This - in case of you tip :) thx - is now working. I prepared already the response and the client receives the data. If the client try to transmit the next data [write(fd, p, s)] the driver does not get next data. TxAvailable isn't called any more. Finally the client runs in timeout. I'm sure that something is missing in my driver extension. DataAvailable() for client RX notification is called. Also TxFreeSpaceAvailable() is called to notify client for more data. But nothing come in again.

What is the next step or what is additional required, that the underlaying code is ready for next data?

I have RX data ready notification

RxDataAvailable Notifies the system that data from the device is now available.

I have TX ready for more data notification.

TxFreeSpaceAvailable Notifies the system that the device is ready to accept more data.

 kernel[0:79b9] () [VSPSerialPort]: ConnectQueues called
 kernel[0:79b9] () IOUserSerial::: 59 0x600001620058
 kernel[0:75fd] (IOUserSerial) IOUserSerial::allocResources: 904 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramMCR: 1115 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramMCR: 1115 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramMCR called -> DTR=1 RTS=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramMCR: 1115 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwActivate: 1069 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwActivate: 1069 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwActivate called.
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:79b9] () IOUserSerial::: 130 0x600001620058
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwActivate: 1069 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwResetFIFO called -> tx=1 rx=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwResetFIFO called -> tx=0 rx=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwResetFIFO: 1076 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwGetModemStatus called [out] CTS=1 DSR=1 RI=0 DCD=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramFlowControl called -> arg=00 xon=11 xoff=13
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramBaudRate called -> baudRate=9600
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=9600 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=9600 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=9600 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramFlowControl called -> arg=00 xon=11 xoff=13
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 ==>0
 kernel[0:79d8] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 <==
 kernel[0:79d8] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwGetModemStatus called [out] CTS=1 DSR=1 RI=0 DCD=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 locklevel = 1
 kernel[0:79d8] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 ==>0
 kernel[0:79b9] () [VSPSerialPort]: HwProgramBaudRate called -> baudRate=9600
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=9600 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=9600 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=9600 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramFlowControl called -> arg=00 xon=11 xoff=13
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramBaudRate called -> baudRate=115200
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramBaudRate: 1107 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=115200 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=115200 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramUART called -> baudRate=115200 nDataBits=8 nHalfStopBits=2 parity=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwProgramUART: 1100 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwProgramFlowControl called -> arg=00 xon=11 xoff=13
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::handleEventFlowControl: 1042 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwGetModemStatus called [out] CTS=1 DSR=1 RI=0 DCD=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwGetModemStatus called [out] CTS=1 DSR=1 RI=0 DCD=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 ==>0
 
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 INTERREST - START
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable called.
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable> IOSPI txPI=4 txCI=0 txqoffset=0 txqlogsz=14
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable> Dump m_txqmd buf=0x10b36c000 len=4
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable> buffer[00]=0x41 A
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable> buffer[01]=0x54 T
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable> buffer[02]=0x0d
 kernel[0:79b9] () [VSPSerialPort]: TxDataAvailable> buffer[03]=0x0a
 kernel[0:79b9] () [VSPSerialPort]: enqueueResponse called.
 kernel[0:79b9] () [VSPSerialPort]: enqueueResponse: RX enqueue data=0x10b37202c size=4
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> IOSPI rxPI=0 rxCI=0 rxqoffset=0 rxqlogsz=14
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent: dequeue RX source
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent: RX dequeue: data=0x10b37202c size=4
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent: Dump m_rxqmd buffer=0x10b366000 size=8
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[00]=0x41 A    <<<<<<<<< copied
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[01]=0x54 T    <<<<<<<<< copied
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[02]=0x0d      <<<<<<<<< copied
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[03]=0x0a      <<<<<<<<< copied
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[04]=0x4f O    <<<<<<<<< added
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[05]=0x4b K    <<<<<<<<< added
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[06]=0x0d      <<<<<<<<< added
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent> buffer[07]=0x0a      <<<<<<<<< added
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: EchoAsyncEvent RX source is empty, done.
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:79b9] () [VSPSerialPort]: TxFreeSpaceAvailable called.    <<<<<<<<<<<<<< _!!_
 kernel[0:79da] () [VSPSerialPort]: NotifyRXReady called.
 kernel[0:79b9] () [VSPSerialPort]: RxDataAvailable called.         <<<<<<<<<<<<<< _!!_
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwGetModemStatus called [out] CTS=0 DSR=1 RI=0 DCD=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 ==>0
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 <==
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 locklevel = 1
 kernel[0:79b9] () [VSPSerialPort]: HwGetModemStatus called [out] CTS=0 DSR=1 RI=0 DCD=0
 kernel[0:79b9] () [VSPSerialPort]: => lock level=1
 kernel[0:79b9] () [VSPSerialPort]: <= lock level=1
 kernel[0:75fd] (IOUserSerial) IOUserSerial::hwGetModemStatus: 1122 ==>0

 ?????? why hold here ??????


:::::::::: Client protokoll : that is happen ....

 [I:00010e5ae600] MOBILE:-----------------------------------------------
 [I:00010e5ae600] MOBILE:Switch to CSMobileNet::Startup flags: 2
 [I:00010e5ae600] QCTGEN: Prepare APN profile setup.
 [I:00010e5ae600] QCTGEN: Using APN profile..: 3 "IP" "web.vodafone.de" "0.0.0.0"
 [I:70000819c000] MOBWRK: Command thread started.
 [D:00010e5ae600] QCTGEN:SEND> AT
 [D:700008843000] QCTGEN:RESP> AT   <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< TX -> RX
 [D:700008843000] QCTGEN:RESP> OK   <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< added OK\r\n
 [D:00010e5ae600] QCTGEN:SEND> ATX4 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< next this stops !!
 [W:00010e5ae600] WRELAY: In progress, skip.
 [W:00010e5ae600] WRELAY: In progress, skip.
 [W:00010e5ae600] WRELAY: In progress, skip.
 [W:70000819c000] MOBWRK: Command timed out. Command: ATX4
 [I:00010e5ae600] MOBILE: Got module soft reset.  <<<<<<<<<<<<<<<<< grrr

// ********************************************************************
// VSPSerialPort - Serial port implementation
//
// Copyright © 2025 by EoF Software Labs
// Copyright © 2024 Apple Inc. (some copied parts)
// SPDX-License-Identifier: MIT
// ********************************************************************

// -- OS
#include 
#include 
#include 

#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 

#include 
#include 
#include 

// -- SerialDriverKit
#include 
#include 
#include 

// -- My
#include "VSPLogger.h"
#include "VSPSerialPort.h"
#include "VSPDriver.h"

#define LOG_PREFIX "VSPSerialPort"

#define kVSPTTYBaseName "vsp"
#define kRxDataQueueName "rxDataQueue"

#ifndef IOLockFreeNULL
#define IOLockFreeNULL(l) { if (NULL != (l)) { IOLockFree(l); (l) = NULL; } }
#endif

#define VSPAquireLock(ivars) \
{ \
    ++ivars->m_lockLevel; \
    VSPLog(LOG_PREFIX, "=> lock level=%d", ivars->m_lockLevel); \
    IOLockLock(ivars->m_lock); \
}

#define VSPUnlock(ivars) \
{ \
    VSPLog(LOG_PREFIX, "<= lock level=%d", ivars->m_lockLevel); \
    --ivars->m_lockLevel; \
    IOLockUnlock(ivars->m_lock); \
}

// Updated by SetModemStatus read by HwGetModemStatus
typedef struct {
    bool cts;
    bool dsr;
    bool ri;
    bool dcd;
} THwSerialStatus;

// Updated by HwProgramFlowControl
typedef struct{
    uint32_t arg;
    uint8_t xon;
    uint8_t xoff;
} THwFlowControl;

// Updated by HwProgramMCR
typedef struct {
    bool dtr;
    bool rts;
} THwMCR;

// Updated by HwProgramUART and HwProgramBaudRate
typedef struct {
    uint32_t baudRate;
    uint8_t nDataBits;
    uint8_t nHalfStopBits;
    uint8_t parity;
} TUartParameters;

// Updated by RxError and HwSendBreak
typedef struct {
    bool overrun;
    bool gotBreak;
    bool framingError;
    bool parityError;
} TErrorState;

// Driver instance state resource
struct VSPSerialPort_IVars {
    IOService* m_provider = nullptr;
    VSPDriver* m_parent = nullptr;

    IOLock* m_lock = nullptr;                       // for resource locking
    volatile atomic_int m_lockLevel = 0;

    /* OS provided memory descriptors by overridden
     * method ConnectQueues(...) */
    IOBufferMemoryDescriptor *m_ifmd = nullptr;     // Interrupt related
    IOBufferMemoryDescriptor *m_txqmd = nullptr;    // OS -> HW Transmit
    IOBufferMemoryDescriptor *m_rxqmd = nullptr;    // HW -> OS Receive
    
    // Timed events
    IODispatchQueue* m_tiQueue = nullptr;
    IOTimerDispatchSource* m_tiSource = nullptr;
    OSAction* m_tiAction = nullptr;
    OSData* m_tiData = nullptr;

    // Response buffer created by TxAvailable()
    IODispatchQueue* m_rxQueue = nullptr;
    IODataQueueDispatchSource* m_rxSource = nullptr;
    OSAction* m_rxAction = nullptr;

    // Serial interface
    TErrorState m_errorState = {};
    TUartParameters m_uartParams = {};
    THwSerialStatus m_hwStatus = {};
    THwFlowControl m_hwFlowControl = {};
    THwMCR m_hwMCR = {};
    uint32_t m_hwLatency = 25;
    
    bool m_txIsComplete = false;
    bool m_hwActivated = false;
};

using namespace driverkit;
using namespace serial;

// --------------------------------------------------------------------
// Allocate internal resources
//
bool VSPSerialPort::init(void)
{
    bool result;
    
    VSPLog(LOG_PREFIX, "init called.\n");
    
    if (!(result = super::init())) {
        VSPLog(LOG_PREFIX, "super::init falsed. result=%d\n", result);
        goto error_exit;
    }
    
    // Create instance state resource
    ivars = IONewZero(VSPSerialPort_IVars, 1);
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Unable to allocate driver data.\n");
        result = false;
        goto error_exit;
    }
    
    return true;
    
error_exit:
    return result;
}

// --------------------------------------------------------------------
// Release internal resources
//
void VSPSerialPort::free(void)
{
    VSPLog(LOG_PREFIX, "free called.\n");
    
    // Release instance state resource
    IOSafeDeleteNULL(ivars, VSPSerialPort_IVars, 1);
    super::free();
}

// --------------------------------------------------------------------
// Start_Impl(IOService* provider)
//
kern_return_t IMPL(VSPSerialPort, Start)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Start: called.\n");
    
    // sane check our driver instance vars
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Start: Private driver instance is NULL\n");
        return kIOReturnInvalid;
    }
    
    // call super method (apple style)
    ret = Start(provider, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start(super): failed. code=%d\n", ret);
        return ret;
    }
    
    // remember OS provider
    ivars->m_provider = provider;

    // the resource locker
    ivars->m_lock = IOLockAlloc();
    if (ivars->m_lock == nullptr) {
        VSPLog(LOG_PREFIX, "Start: Unable to allocate lock object.\n");
        goto error_exit;
    }
    
    // create our own TTY name and index
    if ((ret = setupTTYBaseName()) != kIOReturnSuccess) {
        goto error_exit;
    }

    // default UART parameters
    ivars->m_uartParams.baudRate = 112500;
    ivars->m_uartParams.nHalfStopBits = 2;
    ivars->m_uartParams.nDataBits = 8;
    ivars->m_uartParams.parity = 0;

    VSPLog(LOG_PREFIX, "Start: Allocate timer queue and resources.\n");

    ret = IODispatchQueue::Create("kVSPTimerQueue", 0, 0, &ivars->m_tiQueue);
    if (ret != kIOReturnSuccess || !ivars->m_tiQueue) {
        VSPLog(LOG_PREFIX, "Start: Unable to create timer queue. code=%d\n", ret);
        goto error_exit;
    }

    ret = IOTimerDispatchSource::Create(ivars->m_tiQueue, &ivars->m_tiSource);
    if (ret != kIOReturnSuccess || !ivars->m_tiSource) {
        VSPLog(LOG_PREFIX, "Start: Unable to create timer queue. code=%d\n", ret);
        goto error_exit;
    }

    ret = CreateActionNotifyRXReady(sizeof(ivars->m_tiData), &ivars->m_tiAction);
    if (ret != kIOReturnSuccess || !ivars->m_tiAction) {
        VSPLog(LOG_PREFIX, "Start: Unable to timer callback action. code=%d\n", ret);
        goto error_exit;
    }

    ret = ivars->m_tiSource->SetHandler(ivars->m_tiAction);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: Unable to assign timer action. code=%d\n", ret);
        goto error_exit;
    }

    VSPLog(LOG_PREFIX, "Start: register service.\n");

    // Register driver instance to IOReg
    if ((ret = RegisterService()) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: RegisterService failed. code=%d\n", ret);
        goto error_exit;
    }
    
    VSPLog(LOG_PREFIX, "Start: driver started successfully.\n");
    return kIOReturnSuccess;
    
error_exit:
    cleanupResources();
    Stop(provider, SUPERDISPATCH);
    return ret;
}

// --------------------------------------------------------------------
// Stop_Impl(IOService* provider)
//
kern_return_t IMPL(VSPSerialPort, Stop)
{
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "Stop called.\n");
    
    // Unlink VSP parent
    ivars->m_parent = nullptr;
    
    // Remove all IVars resources
    cleanupResources();
    
    /* Shutdown instane */
    if ((ret= Stop(provider, SUPERDISPATCH)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::Stop failed. code=%d\n", ret);
    } else {
        VSPLog(LOG_PREFIX, "driver successfully removed.\n");
    }
    
    return ret;
}

// --------------------------------------------------------------------
// Remove all resources in IVars
//
void VSPSerialPort::cleanupResources()
{
    VSPLog(LOG_PREFIX, "cleanupResources called.\n");
    
    OSSafeReleaseNULL(ivars->m_tiQueue);
    OSSafeReleaseNULL(ivars->m_tiSource);
    OSSafeReleaseNULL(ivars->m_tiAction);
    OSSafeReleaseNULL(ivars->m_tiData);
    IOLockFreeNULL(ivars->m_lock);
}

// ====================================================================
// ** ----------------[ Connection live cycle&nbsp;]--------------------- **
// ====================================================================

// --------------------------------------------------------------------
// ConnectQueues_Impl( ... )
// First call
kern_return_t IMPL(VSPSerialPort, ConnectQueues)
{
    VSPLog(LOG_PREFIX, "ConnectQueues called\n");

    IOReturn ret = ConnectQueues(ifmd, rxqmd, txqmd,
                                 in_rxqmd,
                                 in_txqmd,
                                 in_rxqoffset,
                                 in_txqoffset,
                                 in_rxqlogsz,
                                 in_txqlogsz, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::ConnectQueues failed. code=%d\n", ret);
        return ret;
    }
    
    //-- Sane check --//
    if (!ifmd || !(*ifmd) || !txqmd || !(*txqmd) || !rxqmd || !(*rxqmd)) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid memory descriptors detected. (NULL)\n");
        return kIOReturnBadArgument;
    }
    ivars->m_ifmd = OSDynamicCast(IOBufferMemoryDescriptor, (*ifmd));
    if (ivars->m_ifmd == nullptr) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'ifmd' memory descriptor detected.\n");
        return kIOReturnInvalid;
    }
    ivars->m_txqmd = OSDynamicCast(IOBufferMemoryDescriptor, (*txqmd));
    if (ivars->m_txqmd == nullptr) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'txqmd' memory descriptor detected.\n");
        return kIOReturnInvalid;
    }
    ivars->m_rxqmd = OSDynamicCast(IOBufferMemoryDescriptor, (*rxqmd));
    if (ivars->m_rxqmd == nullptr) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'rxqmd' memory descriptor detected.\n");
        return kIOReturnInvalid;
    }
    
    // -- Setup RX response queue and dispatch source --
    
    uint64_t size;
    if ((ret = ivars->m_rxqmd->GetLength(&size)) != kIOReturnSuccess || size == 0) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to descriptor size.\n");
        return ret;
    }
 
    // 0 = No options are currently defined.
    // 0 = No priorities are currently defined.
    ret = IODispatchQueue::Create(kRxDataQueueName, 0, 0, &ivars->m_rxQueue);
    if (ret != kIOReturnSuccess || !ivars->m_rxQueue) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to create RX queue. code=%d\n", ret);
        return ret;
    }
    
    ret = IODataQueueDispatchSource::Create(size, ivars->m_rxQueue, &ivars->m_rxSource);
    if (ret != kIOReturnSuccess || !ivars->m_rxSource) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to creade dispatch soure. code=%d\n", ret);
        goto error_exit;
    }

    // Async notification from IODataQueueDispatchSource::DataAvailable
    ret = CreateActionEchoAsyncEvent(size, &ivars->m_rxAction);
    if (ret != kIOReturnSuccess || !ivars->m_rxAction) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to create RX action. code=%d\n", ret);
        goto error_exit;
    }
    
    // Set async async callback action
    ret = ivars->m_rxSource->SetDataAvailableHandler(ivars->m_rxAction);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "ConnectQueues: SetDataAvailableHandler failed. code=%d\n", ret);
        goto error_exit;
    }

    return kIOReturnSuccess;
    
error_exit:
    OSSafeReleaseNULL(ivars->m_rxAction);
    OSSafeReleaseNULL(ivars->m_rxSource);
    OSSafeReleaseNULL(ivars->m_rxQueue);
    return ret;
}

// --------------------------------------------------------------------
// DisconnectQueues_Impl()
// Last call
kern_return_t IMPL(VSPSerialPort, DisconnectQueues)
{
    IOReturn ret;

    VSPLog(LOG_PREFIX, "DisconnectQueues called\n");
    
    // stop RX dispatch queue
    OSSafeReleaseNULL(ivars->m_rxSource);
    OSSafeReleaseNULL(ivars->m_rxAction);
    OSSafeReleaseNULL(ivars->m_rxQueue);

    // reset obtained MD pointers
    ivars->m_txqmd = nullptr;
    ivars->m_rxqmd = nullptr;
    ivars->m_ifmd  = nullptr;

    ret = DisconnectQueues(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::DisconnectQueues: failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// NotifyRXReady_Impl(OSAction* action)
// Called by timer dispatch queue source
void IMPL(VSPSerialPort, NotifyRXReady)
{
    VSPLog(LOG_PREFIX, "NotifyRXReady called.\n");
    
    // Make sure action object is valid
    if (!action) {
        VSPLog(LOG_PREFIX, "NotifyRXReady bad argument. action=0%llx\n", (uint64_t) action);
        return;
    }
    
    // Notify IOUserSerial rx data ready to dispatch
    RxDataAvailable();
}

// --------------------------------------------------------------------
// EchoAsyncEvent_Impl(OSAction* action)
// Called by RX data available dispatch queue source
void IMPL(VSPSerialPort, EchoAsyncEvent)
{
    SerialPortInterface* spi;
    IOAddressSegment ifseg;
    IOAddressSegment rxseg;
    IOReturn ret;
    char* buf;
    
    // Make sure action object is valid
    if (!action) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent bad argument. action=0%llx\n", (uint64_t) action);
        return;
    }

    // Lock to ensure thread safety
    VSPAquireLock(ivars);

    // skip if complete...
    if (!ivars->m_rxSource->IsDataAvailable()) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent RX source is empty, done.\n");
        goto finished;
    }

    // Lock RX dispatch queue source
    if ((ret = ivars->m_rxSource->SetEnable(false)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent: RX source SetEnable false failed. code=%d\n", ret);
        goto finished;
    }

    // Get the address of the IOSerialPortInterface
    if ((ret = ivars->m_ifmd->GetAddressRange(&ifseg)) != kIOReturnSuccess) {
       VSPLog(LOG_PREFIX, "EchoAsyncEvent: IF GetAddressRange failed. code=%d\n", ret);
       goto finished;
    }

    // Get the address of the RX ring buffer
    if ((ret = ivars->m_rxqmd->GetAddressRange(&rxseg)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent: RX GetAddressRange failed. code=%d\n", ret);
        goto finished;
    }
    
    // IF address to the serial port interface
    spi = (SerialPortInterface*) ifseg.address;
    
    VSPLog(LOG_PREFIX, "EchoAsyncEvent> IOSPI rxPI=%d rxCI=%d rxqoffset=%d rxqlogsz=%d\n",
           spi->rxPI, spi->rxCI, spi->rxqoffset, spi->rxqlogsz);

    // RX address to the RX ring buffer
    buf = (char*) rxseg.address;

    VSPLog(LOG_PREFIX, "EchoAsyncEvent: dequeue RX source\n");

    // Remove queue entry from RX queue source
    ret = ivars->m_rxSource->Dequeue(^(const void *data, size_t dataSize) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent: RX dequeue: data=0x%llx size=%ld\n", (uint64_t) data, dataSize);
        // Copy to RX ring buffer
        memcpy(buf, data, dataSize);
        // Update RX producer index
        spi->rxPI = (uint32_t) dataSize;
    });
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent: RX dequeue failed. code=%d\n", ret);
        switch (ret) {
            case kIOReturnUnderrun:
                VSPLog(LOG_PREFIX, "EchoAsyncEvent: ^^-> underrun\n");
                break;
            case kIOReturnError:
                VSPLog(LOG_PREFIX, "EchoAsyncEvent: ^^-> corrupt\n");
                return;
        }
    }
    
    buf[spi->rxPI++] = 'O';
    buf[spi->rxPI++] = 'K';
    buf[spi->rxPI++] = '\r';
    buf[spi->rxPI++] = '\n';


#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "EchoAsyncEvent: Dump m_rxqmd buffer=0x%llx size=%u\n", (uint64_t) buf, spi->rxPI);
    for (uint64_t i = 0; i < spi->rxPI; i++) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent> buffer[%02lld]=0x%02x %c\n", i, buf[i], buf[i]);
    }
#endif

    // Unlock RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(true)) != kIOReturnSuccess) {
       VSPLog(LOG_PREFIX, "EchoAsyncEvent: RX source SetEnable true failed. code=%d\n", ret);
       goto finished;
    }
    
    // Notify queue entry has been removed
    ivars->m_rxSource->SendDataServiced();
   
    // ???
    ivars->m_hwStatus.cts = false;
    
    // Notifies TX is ready for mode data
    // from client instance
    TxFreeSpaceAvailable();

    // Notify RX completion to OS interrest parties
    // using client defined latency time
    ret = ivars->m_tiSource->WakeAtTime(
                kIOTimerClockMonotonicRaw,
                clock_gettime_nsec_np(CLOCK_MONOTONIC_RAW) + ivars->m_hwLatency,
                1000000000);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "EchoAsyncEvent> tiSource WakeAtTime failed. code=%d\n", ret);
        goto finished;
    }

finished:
    VSPUnlock(ivars);
}

// --------------------------------------------------------------------
// TxDataAvailable_Impl()
// Called on TX data income
void IMPL(VSPSerialPort, TxDataAvailable)
{
    SerialPortInterface* spi;
    IOAddressSegment ifseg;
    IOAddressSegment txseg;
    char* buf;
    uint64_t len;
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "TxDataAvailable called.\n");
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);

    // Reset first
    ivars->m_txIsComplete = false;

    // Get the address of the IOSerialPortInterface buffer
    if ((ret = ivars->m_ifmd->GetAddressRange(&ifseg)) != kIOReturnSuccess) {
       VSPLog(LOG_PREFIX, "TxDataAvailable: IF GetAddressRange failed. code=%d\n", ret);
       goto finished;
    }

    // Get the address of the TX ring buffer
    if ((ret = ivars->m_txqmd->GetAddressRange(&txseg)) != kIOReturnSuccess) {
       VSPLog(LOG_PREFIX, "TxDataAvailable: TX GetAddressRange failed. code=%d\n", ret);
       goto finished;
    }

    /* serial port interface segment */
    spi = (SerialPortInterface*) ifseg.address;

    VSPLog(LOG_PREFIX, "TxDataAvailable> IOSPI txPI=%d txCI=%d txqoffset=%d txqlogsz=%d\n",
           spi->txPI, spi->txCI, spi->txqoffset, spi->txqlogsz);

    // skip if nothing to do
    if (!spi->txPI) {
        goto finished;
    }
    
    /* txProducer: number bytes comming in */
    len = spi->txPI;
    
    /* Address to the TX ring buffer */
    buf = (char*) txseg.address;

#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "TxDataAvailable> Dump m_txqmd buf=0x%llx len=%llu\n", (uint64_t) buf, len);
    for (uint64_t i = 0; i < len; i++) {
        VSPLog(LOG_PREFIX, "TxDataAvailable> buffer[%02lld]=0x%02x %c\n", i, buf[i], buf[i]);
    }
#endif
    
    // Enqueue TX as response (echo)
    if ((ret = enqueueResponse(buf, len, spi)) != kIOReturnSuccess) {
       VSPLog(LOG_PREFIX, "TxDataAvailable: Enqueue response failed. code=%d\n", ret);
       goto finished;
    }

    // Raise response event
    ivars->m_txIsComplete = true;
    ivars->m_rxSource->SendDataAvailable();
    
finished:
    VSPUnlock(ivars);
}

// --------------------------------------------------------------------
// Enque given buffer in RX dispatch source and raise async event
// Enqueue given buffer into RX dispatch queue source
kern_return_t VSPSerialPort::enqueueResponse(void* buffer, uint64_t size, void* spif)
{
    IOReturn ret = 0;

    VSPLog(LOG_PREFIX, "enqueueResponse called.\n");

    // Make sure everything is fine
    if (!ivars || !ivars->m_rxSource || !buffer || !size) {
        VSPLog(LOG_PREFIX, "enqueueResponse: Invalid arguments\n");
        return kIOReturnBadArgument;
    }
    
    // Disable dispatching on RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(false)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX source disable failed. code=%d\n", ret);
        return ret;
    }

    // Response by adding queue entry to RX queue source
    ret = ivars->m_rxSource->Enqueue((uint32_t) size, ^(void *data, size_t dataSize) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX enqueue data=0x%llx size=%lld\n", (uint64_t) data, size);
        memcpy(data, buffer, (dataSize < size ? dataSize : size));
    });
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX enqueue failed. code=%d\n", ret);
        switch (ret) {
            case kIOReturnOverrun:
                VSPLog(LOG_PREFIX, "enqueueResponse: ^^-> overrun\n");
                break;
            case kIOReturnError:
                VSPLog(LOG_PREFIX, "enqueueResponse: ^^-> corrupt\n");
                break;
        }
        // Leave dispatch disabled (??)
        return ret;
    }
    
    // Enable dispatching on RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(true)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX source enable failed. code=%d\n", ret);
        return ret;
    }
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// RxFreeSpaceAvailable_Impl()
// Notification to this instance that RX buffer space is available for
// your device’s data
void IMPL(VSPSerialPort, RxFreeSpaceAvailable)
{
    VSPLog(LOG_PREFIX, "RxFreeSpaceAvailable called.\n");
    RxFreeSpaceAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// TxFreeSpaceAvailable_Impl()
// Notify OS ready for more client data
void IMPL(VSPSerialPort, TxFreeSpaceAvailable)
{
    VSPLog(LOG_PREFIX, "TxFreeSpaceAvailable called.\n");
    TxFreeSpaceAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// RxDataAvailable_Impl()
// Notify OS response RX data ready for client
void IMPL(VSPSerialPort, RxDataAvailable)
{
    VSPLog(LOG_PREFIX, "RxDataAvailable called.\n");
    RxDataAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// SetModemStatus_Impl(bool cts, bool dsr, bool ri, bool dcd)
// Called during serial port setup or communication
kern_return_t IMPL(VSPSerialPort, SetModemStatus)
{
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "SetModemStatus called [in] CTS=%d DSR=%d RI=%d DCD=%d\n",
               cts, dsr, ri, dcd);
    
    VSPAquireLock(ivars);
    ivars->m_hwStatus.cts = cts;
    ivars->m_hwStatus.dsr = dsr;
    ivars->m_hwStatus.ri  = ri;
    ivars->m_hwStatus.dcd = dcd;
    VSPUnlock(ivars);
    
    ret = SetModemStatus(cts, dsr, ri, dcd, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::SetModemStatus failed. code=%d\n", ret);
        return ret;
    }

    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// RxError_Impl(bool overrun, bool break, bool framing, bool parity)
// Called on given error states
kern_return_t IMPL(VSPSerialPort, RxError)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "RxError called.\n");
    
    if (overrun) {
        VSPLog(LOG_PREFIX, "RX overrun.\n");
    }
    
    if (gotBreak) {
        VSPLog(LOG_PREFIX, "RX got break.\n");
    }
    
    if (framingError) {
        VSPLog(LOG_PREFIX, "RX framing error.\n");
    }
    
    if (parityError) {
        VSPLog(LOG_PREFIX, "RX parity error.\n");
    }
    
    VSPAquireLock(ivars);
    ivars->m_errorState.overrun = overrun;
    ivars->m_errorState.framingError = framingError;
    ivars->m_errorState.gotBreak = gotBreak;
    ivars->m_errorState.parityError = parityError;
    VSPUnlock(ivars);
    
    ret = RxError(overrun, gotBreak, framingError, parityError, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::RxError: failed. code=%d\n", ret);
        return ret;
    }

    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwActivate_Impl()
// Called after ConnectQueues() or other reasons
kern_return_t IMPL(VSPSerialPort, HwActivate)
{
    kern_return_t ret = kIOReturnIOError;
    
    VSPLog(LOG_PREFIX, "HwActivate called.\n");
    
    VSPAquireLock(ivars);
    ivars->m_hwActivated = true;
    VSPUnlock(ivars);
    
    ret = HwActivate(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::HwActivate failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// HwDeactivate_Impl()
// Called before DisconnectQueues() or other reasons
kern_return_t IMPL(VSPSerialPort, HwDeactivate)
{
    kern_return_t ret = kIOReturnIOError;
    
    VSPLog(LOG_PREFIX, "HwDeactivate called.\n");
    
    VSPAquireLock(ivars);
    ivars->m_hwActivated = false;
    VSPUnlock(ivars);
    
    ret = HwDeactivate(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::HwDeactivate failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// HwResetFIFO_Impl()
// Called by client to TxFreeSpaceAvailable or RxFreeSpaceAvailable
// or other reasons.
kern_return_t IMPL(VSPSerialPort, HwResetFIFO)
{
    VSPLog(LOG_PREFIX, "HwResetFIFO called -> tx=%d rx=%d\n",
               tx, rx);
    
    VSPAquireLock(ivars);
    // ?? notify caller (IOUserSerial)
    if (rx) {
        ivars->m_hwStatus.cts = true;
        ivars->m_hwStatus.dsr = true;
    }
    
    // ?? notify caller (IOUserSerial)
    if (tx) {
        ivars->m_hwStatus.cts = true;
        ivars->m_hwStatus.dsr = true;
    }
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwSendBreak_Impl()
// Called during client communication life cycle
kern_return_t IMPL(VSPSerialPort, HwSendBreak)
{
    VSPLog(LOG_PREFIX, "HwSendBreak called -> sendBreak=%d\n", sendBreak);
    
    VSPAquireLock(ivars);
    ivars->m_errorState.gotBreak = sendBreak;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwGetModemStatus_Impl()
// Called during client communication life cycle
kern_return_t IMPL(VSPSerialPort, HwGetModemStatus)
{
    VSPLog(LOG_PREFIX, "HwGetModemStatus called [out] CTS=%d DSR=%d RI=%d DCD=%d\n", //
               ivars->m_hwStatus.cts, ivars->m_hwStatus.dsr, //
               ivars->m_hwStatus.ri, ivars->m_hwStatus.dcd);
    
    VSPAquireLock(ivars);
    if (cts != nullptr) {
        (*cts) = ivars->m_hwStatus.cts;
    }
    
    if (dsr != nullptr) {
        (*dsr) = ivars->m_hwStatus.dsr;
    }
    
    if (ri != nullptr) {
        (*ri) = ivars->m_hwStatus.ri;
    }
    
    if (dcd != nullptr) {
        (*dcd) = ivars->m_hwStatus.dcd;
    }
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramUART_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramUART)
{
    VSPLog(LOG_PREFIX, "HwProgramUART called -> baudRate=%d "
                        "nDataBits=%d nHalfStopBits=%d parity=%d\n",
            baudRate, nDataBits, nHalfStopBits, parity);
    
    VSPAquireLock(ivars);
    ivars->m_uartParams.baudRate = baudRate;
    ivars->m_uartParams.nDataBits = nDataBits;
    ivars->m_uartParams.nHalfStopBits = nHalfStopBits;
    ivars->m_uartParams.parity = parity;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramBaudRate_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramBaudRate)
{
    VSPLog(LOG_PREFIX, "HwProgramBaudRate called -> baudRate=%d\n", baudRate);
    
    VSPAquireLock(ivars);
    ivars->m_uartParams.baudRate = baudRate;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramMCR_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramMCR)
{
    VSPLog(LOG_PREFIX, "HwProgramMCR called -> DTR=%d RTS=%d\n",
               dtr, rts);
    
    VSPAquireLock(ivars);
    ivars->m_hwMCR.dtr = dtr;
    ivars->m_hwMCR.rts = rts;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramLatencyTimer_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramLatencyTimer)
{
    VSPLog(LOG_PREFIX, "HwProgramLatencyTimer called -> latency=%d\n",
               latency);
    
    VSPAquireLock(ivars);
    ivars->m_hwLatency = latency;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramLatencyTimer_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramFlowControl)
{
    VSPLog(LOG_PREFIX, "HwProgramFlowControl called -> arg=%02x xon=%02x xoff=%02x\n",
               arg, xon, xoff);
    
    VSPAquireLock(ivars);
    ivars->m_hwFlowControl.arg = arg;
    ivars->m_hwFlowControl.xon = xon;
    ivars->m_hwFlowControl.xoff = xoff;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Called by VSPDriver instance to link to parent level
//
void VSPSerialPort::setParent(VSPDriver* parent)
{
    VSPLog(LOG_PREFIX, "setParent called.\n");

    if (ivars != nullptr && !ivars->m_parent) {
        ivars->m_parent = parent;
    }
}

// --------------------------------------------------------------------
// Called by VSPDriver instance to set TTY base and number based on
// managed instance of this object instance
kern_return_t VSPSerialPort::setupTTYBaseName()
{
    IOReturn ret;
    OSDictionary* properties = nullptr;
    OSString* baseName = nullptr;
 
    VSPLog(LOG_PREFIX, "setupTTYBaseName called.\n");

    // setup custom TTY name
    if ((ret = CopyProperties(&properties)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "setupTTYBaseName: Unable to get properties. code=%d\n", ret);
        return ret;
    }
    
    baseName = OSString::withCString(kVSPTTYBaseName);
    properties->setObject(kIOTTYBaseNameKey, baseName);
    
    // write back to driver instance
    if ((ret = SetProperties(properties)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "setupTTYBaseName: Unable to set TTY base name. code=%d\n", ret);
        //return ret; // ??? an error - why???
    }
    
    OSSafeReleaseNULL(baseName);
    OSSafeReleaseNULL(properties);
    return kIOReturnSuccess;
}

Best regards Bjoern

Ah okay, yes I should file bugs. Well, a question about the step after receiving TX data. This - in case of you tip :) thx - is now working. I prepared already the response and the client receives the data. If the client try to transmit the next data [write(fd, p, s)] the driver does not get next data. TxAvailable isn't called any more. Finally the client runs in timeout. I'm sure that something is missing in my driver extension. DataAvailable() for client RX notification is called. Also TxFreeSpaceAvailable() is called to notify client for more data.

The thing you're missing is that the primary interface that "communicates" data between the system and you is the "SerialPortInterface" structure, not the methods themselves. So, for example, "TxFreeSpaceAvailable" doesn't simply mean "I have free space available" but actually means "I have free space available AND go look at the SerialPortInterface to figure out what's happened".

You need to update those indexes as you process data so that the system understands that data is being processed so it can feed you more data.

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

Hi Kevin, okay got it.

    // Calculate available data in TX buffer
    size = ivars->m_spi->txPI - ivars->m_spi->txCI;
    
    // Get address of new TX data position
    address = ivars->m_txseg.address + ivars->m_spi->txCI;
    buffer = reinterpret_cast<uint8_t*>(address);

    /* -- do something with the buffer content -- */

    // Notify OS
    // Reset TX consumer index to end of received block
    ivars->m_spi->txCI = ivars->m_spi->txPI;

The part above calls TxAvailable() at every client transmission and increases txPI and txCI like an offset. That's for me unexpected. Here the next question:

  1. What happen, if the txPI and txCI reach the end of the TX memory descriptor? ;)
  2. Does the OS reset txPI and txCI to the beginning? -> it seems not to be.

If I report txCI = txPI and txPI = 0, the call to TxAvailable is only executed once, but in my opinion/expectation it should start again at the beginning of the TX buffer.

// ********************************************************************
// VSPSerialPort - Serial port implementation
//
// Copyright © 2025 by EoF Software Labs
// Copyright © 2024 Apple Inc. (some copied parts)
// SPDX-License-Identifier: MIT
// ********************************************************************

// -- OS
#include 
#include 
#include 
#include 

#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 

#include 
#include 
#include 

// -- SerialDriverKit
#include 
#include 
#include 
using namespace driverkit::serial;

// -- My
#include "VSPLogger.h"
#include "VSPSerialPort.h"
#include "VSPDriver.h"

#define LOG_PREFIX "VSPSerialPort"

#define kVSPTTYBaseName "vsp"
#define kRxDataQueueName "rxDataQueue"

#ifndef IOLockFreeNULL
#define IOLockFreeNULL(l) { if (NULL != (l)) { IOLockFree(l); (l) = NULL; } }
#endif

#define VSPAquireLock(ivars) \
{ \
    ++ivars->m_lockLevel; \
    VSPLog(LOG_PREFIX, "=> lock level=%d", ivars->m_lockLevel); \
    IOLockLock(ivars->m_lock); \
}

#define VSPUnlock(ivars) \
{ \
    VSPLog(LOG_PREFIX, "<= lock level=%d", ivars->m_lockLevel); \
    --ivars->m_lockLevel; \
    IOLockUnlock(ivars->m_lock); \
}

// Updated by SetModemStatus read by HwGetModemStatus
typedef struct {
    bool cts;
    bool dsr;
    bool ri;
    bool dcd;
} THwSerialStatus;

// Updated by HwProgramFlowControl
typedef struct{
    uint32_t arg;
    uint8_t xon;
    uint8_t xoff;
} THwFlowControl;

// Updated by HwProgramMCR
typedef struct {
    bool dtr;
    bool rts;
} THwMCR;

// Updated by HwProgramUART and HwProgramBaudRate
typedef struct {
    uint32_t baudRate;
    uint8_t nDataBits;
    uint8_t nHalfStopBits;
    uint8_t parity;
} TUartParameters;

// Updated by RxError and HwSendBreak
typedef struct {
    bool overrun;
    bool gotBreak;
    bool framingError;
    bool parityError;
} TErrorState;

typedef struct {
    uint8_t* buffer;
    uint32_t length;
} TRXBufferState;

// Driver instance state resource
struct VSPSerialPort_IVars {
    IOService* m_provider = nullptr;
    VSPDriver* m_parent = nullptr;

    IOLock* m_lock = nullptr;                       // for resource locking
    volatile atomic_int m_lockLevel = 0;

    /* OS provided memory descriptors by overridden
     * method ConnectQueues(...) */
    SerialPortInterface* m_spi;                     // OS serial port interface
    
    IOBufferMemoryDescriptor* m_txqbmd;              // VSP TX queue memory descriptor
    IOAddressSegment m_txseg = {};                  // VSP TX buffer segment
    
    IOBufferMemoryDescriptor* m_rxqbmd;              // VSP RX queue memory descriptor
    IOAddressSegment m_rxseg = {};                  // VSP RX buffer segment
    
    TRXBufferState m_rxstate = {};                  // RX dequeue data
    
    // Timed events
    IODispatchQueue* m_tiQueue = nullptr;
    IOTimerDispatchSource* m_tiSource = nullptr;
    OSAction* m_tiAction = nullptr;
    OSData* m_tiData = nullptr;

    // Response buffer created by TxAvailable()
    IODispatchQueue* m_rxQueue = nullptr;
    IODataQueueDispatchSource* m_rxSource = nullptr;
    OSAction* m_rxAction = nullptr;

    // Serial interface
    TErrorState m_errorState = {};
    TUartParameters m_uartParams = {};
    THwSerialStatus m_hwStatus = {};
    THwFlowControl m_hwFlowControl = {};
    THwMCR m_hwMCR = {};
    uint32_t m_hwLatency = 25;
    
    bool m_txIsComplete = false;
    bool m_rxIsComplete = false;
    bool m_hwActivated = false;
};

// --------------------------------------------------------------------
// Allocate internal resources
//
bool VSPSerialPort::init(void)
{
    bool result;
    
    VSPLog(LOG_PREFIX, "init called.\n");
    
    if (!(result = super::init())) {
        VSPLog(LOG_PREFIX, "super::init falsed. result=%d\n", result);
        goto error_exit;
    }
    
    // Create instance state resource
    ivars = IONewZero(VSPSerialPort_IVars, 1);
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Unable to allocate driver data.\n");
        result = false;
        goto error_exit;
    }
    
    return true;
    
error_exit:
    return result;
}

// --------------------------------------------------------------------
// Release internal resources
//
void VSPSerialPort::free(void)
{
    VSPLog(LOG_PREFIX, "free called.\n");
    
    // Release instance state resource
    IOSafeDeleteNULL(ivars, VSPSerialPort_IVars, 1);
    super::free();
}

// --------------------------------------------------------------------
// Start_Impl(IOService* provider)
//
kern_return_t IMPL(VSPSerialPort, Start)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Start: called.\n");
    
    // sane check our driver instance vars
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Start: Private driver instance is NULL\n");
        return kIOReturnInvalid;
    }
    
    // call super method (apple style)
    ret = Start(provider, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start(super): failed. code=%d\n", ret);
        return ret;
    }
    
    // remember OS provider
    ivars->m_provider = provider;

    // the resource locker
    ivars->m_lock = IOLockAlloc();
    if (ivars->m_lock == nullptr) {
        VSPLog(LOG_PREFIX, "Start: Unable to allocate lock object.\n");
        goto error_exit;
    }
    
    // create our own TTY name and index
    if ((ret = setupTTYBaseName()) != kIOReturnSuccess) {
        goto error_exit;
    }

    // default UART parameters
    ivars->m_uartParams.baudRate = 112500;
    ivars->m_uartParams.nHalfStopBits = 2;
    ivars->m_uartParams.nDataBits = 8;
    ivars->m_uartParams.parity = 0;

    VSPLog(LOG_PREFIX, "Start: Allocate timer queue and resources.\n");

    ret = IODispatchQueue::Create("kVSPTimerQueue", 0, 0, &ivars->m_tiQueue);
    if (ret != kIOReturnSuccess || !ivars->m_tiQueue) {
        VSPLog(LOG_PREFIX, "Start: Unable to create timer queue. code=%d\n", ret);
        goto error_exit;
    }

    ret = IOTimerDispatchSource::Create(ivars->m_tiQueue, &ivars->m_tiSource);
    if (ret != kIOReturnSuccess || !ivars->m_tiSource) {
        VSPLog(LOG_PREFIX, "Start: Unable to create timer queue. code=%d\n", ret);
        goto error_exit;
    }

    ret = CreateActionNotifyRXReady(sizeof(ivars->m_tiData), &ivars->m_tiAction);
    if (ret != kIOReturnSuccess || !ivars->m_tiAction) {
        VSPLog(LOG_PREFIX, "Start: Unable to timer callback action. code=%d\n", ret);
        goto error_exit;
    }

    ret = ivars->m_tiSource->SetHandler(ivars->m_tiAction);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: Unable to assign timer action. code=%d\n", ret);
        goto error_exit;
    }

    VSPLog(LOG_PREFIX, "Start: register service.\n");

    // Register driver instance to IOReg
    if ((ret = RegisterService()) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: RegisterService failed. code=%d\n", ret);
        goto error_exit;
    }
    
    VSPLog(LOG_PREFIX, "Start: driver started successfully.\n");
    return kIOReturnSuccess;
    
error_exit:
    cleanupResources();
    Stop(provider, SUPERDISPATCH);
    return ret;
}

// --------------------------------------------------------------------
// Stop_Impl(IOService* provider)
//
kern_return_t IMPL(VSPSerialPort, Stop)
{
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "Stop called.\n");
    
    // Unlink VSP parent
    ivars->m_parent = nullptr;
    
    // Remove all IVars resources
    cleanupResources();
    
    /* Shutdown instane */
    if ((ret= Stop(provider, SUPERDISPATCH)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::Stop failed. code=%d\n", ret);
    } else {
        VSPLog(LOG_PREFIX, "driver successfully removed.\n");
    }
    
    return ret;
}

// --------------------------------------------------------------------
// Remove all resources in IVars
//
void VSPSerialPort::cleanupResources()
{
    VSPLog(LOG_PREFIX, "cleanupResources called.\n");
    
    OSSafeReleaseNULL(ivars->m_tiQueue);
    OSSafeReleaseNULL(ivars->m_tiSource);
    OSSafeReleaseNULL(ivars->m_tiAction);
    OSSafeReleaseNULL(ivars->m_tiData);

    IOLockFreeNULL(ivars->m_lock);
}

// ====================================================================
// ** ----------------[ Connection live cycle&nbsp;]--------------------- **
// ====================================================================

// --------------------------------------------------------------------
// ConnectQueues_Impl( ... )
// First call
kern_return_t IMPL(VSPSerialPort, ConnectQueues)
{
    IOAddressSegment ifseg = {};
    size_t txsize, rxsize;
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "ConnectQueues called\n");
 
    //-- Sane check --//
    if (!in_txqlogsz || !in_rxqlogsz) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid in_rxqlogsz or in_txqlogsz detected.\n");
        return kIOReturnBadArgument;
    }
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);

    // Convert the base-2 logarithmic size of the buffer or the in_txqmd parameter.
    txsize = (size_t) ::pow(2, in_txqlogsz);
    ret = IOBufferMemoryDescriptor::Create(kIOMemoryDirectionIn, txsize, 0, &ivars->m_txqbmd);
    if (ret != kIOReturnSuccess || !ivars->m_txqbmd) {
        VSPLog(LOG_PREFIX, "Start: Unable to create TX memory descriptor. code=%d\n", ret);
        goto error_exit;
    }

    // Convert the base-2 logarithmic size of the buffer for the in_rxqmd parameter.
    rxsize = (size_t) pow(2, in_rxqlogsz);
    ret = IOBufferMemoryDescriptor::Create(kIOMemoryDirectionOut, rxsize, 0, &ivars->m_rxqbmd);
    if (ret != kIOReturnSuccess || !ivars->m_rxqbmd) {
        VSPLog(LOG_PREFIX, "Start: Unable to create RX memory descriptor. code=%d\n", ret);
        goto error_exit;
    }
    
    // make sure the parameters are zero
    in_rxqoffset = 0;
    in_txqoffset = 0;

    // Call super to get SerialPortInterface and set our RX/TX memory descriptors
    ret = ConnectQueues(ifmd, rxqmd, txqmd,
                        ivars->m_rxqbmd,
                        ivars->m_txqbmd,
                        in_rxqoffset,
                        in_txqoffset,
                        in_rxqlogsz,
                        in_txqlogsz, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::ConnectQueues failed. code=%d\n", ret);
        goto error_exit;
    }
    
    //-- Sane check --//
    if (!ifmd || !(*ifmd) || !txqmd || !(*txqmd) || !rxqmd || !(*rxqmd)) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid memory descriptors detected. (NULL)\n");
        ret = kIOReturnBadArgument;
        goto error_exit;
    }
    if ((*txqmd) != ivars->m_txqbmd) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'txqmd' memory descriptor detected.\n");
        ret = kIOReturnInvalid;
        goto error_exit;
    }
    if ((*rxqmd) != ivars->m_rxqbmd) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'rxqmd' memory descriptor detected.\n");
        ret = kIOReturnInvalid;
        goto error_exit;
    }
    
    // Get the address of the TX memory descriptor
    ret = ivars->m_txqbmd->GetAddressRange(&ivars->m_txseg);
    if (ret != kIOReturnSuccess || !ivars->m_txseg.address || ivars->m_txseg.length != txsize) {
        VSPLog(LOG_PREFIX, "Start: Unable to get TX-MD segment. code=%d\n", ret);
        goto error_exit;
    }

    // Get the address of the RX memory descriptor
    ret = ivars->m_rxqbmd->GetAddressRange(&ivars->m_rxseg);
    if (ret != kIOReturnSuccess || !ivars->m_rxseg.address || ivars->m_rxseg.length != rxsize) {
        VSPLog(LOG_PREFIX, "Start: Unable to get TX-MD segment. code=%d\n", ret);
        goto error_exit;
    }

    // Get the address of the IOSerialPortInterface segment (mapped space)
    if ((ret = (*ifmd)->GetAddressRange(&ifseg)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "ConnectQueues: IF GetAddressRange failed. code=%d\n", ret);
        goto error_exit;
    }
   
    // Initialize the indexes
    ivars->m_spi = reinterpret_cast(ifseg.address);
    ivars->m_spi->txCI = 0;
    ivars->m_spi->txPI = 0;
    
    // -- Setup RX response queue and dispatch source --
  
    // 0 = No options are currently defined.
    // 0 = No priorities are currently defined.
    ret = IODispatchQueue::Create(kRxDataQueueName, 0, 0, &ivars->m_rxQueue);
    if (ret != kIOReturnSuccess || !ivars->m_rxQueue) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to create RX queue. code=%d\n", ret);
        goto error_exit;
    }
    
    ret = IODataQueueDispatchSource::Create(ivars->m_rxseg.length, ivars->m_rxQueue, &ivars->m_rxSource);
    if (ret != kIOReturnSuccess || !ivars->m_rxSource) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to creade dispatch soure. code=%d\n", ret);
        goto error_exit;
    }

    // Async notification from IODataQueueDispatchSource::DataAvailable
    ret = CreateActionRxEchoAsyncEvent(ivars->m_rxseg.length, &ivars->m_rxAction);
    if (ret != kIOReturnSuccess || !ivars->m_rxAction) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to create RX action. code=%d\n", ret);
        goto error_exit;
    }
    
    // Set async async callback action
    ret = ivars->m_rxSource->SetDataAvailableHandler(ivars->m_rxAction);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "ConnectQueues: SetDataAvailableHandler failed. code=%d\n", ret);
        goto error_exit;
    }

    // Modem is ready
    ivars->m_hwStatus.dcd = true;
    ivars->m_hwStatus.cts = true;

    VSPUnlock(ivars);
    return kIOReturnSuccess;
    
error_exit:
    OSSafeReleaseNULL(ivars->m_txqbmd);
    OSSafeReleaseNULL(ivars->m_rxqbmd);
    OSSafeReleaseNULL(ivars->m_rxAction);
    OSSafeReleaseNULL(ivars->m_rxSource);
    OSSafeReleaseNULL(ivars->m_rxQueue);
    VSPUnlock(ivars);
    return ret;
}

// --------------------------------------------------------------------
// DisconnectQueues_Impl()
// Last call
kern_return_t IMPL(VSPSerialPort, DisconnectQueues)
{
    IOReturn ret;

    VSPLog(LOG_PREFIX, "DisconnectQueues called\n");
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);

    // stop RX dispatch queue
    OSSafeReleaseNULL(ivars->m_rxSource);
    OSSafeReleaseNULL(ivars->m_rxAction);
    OSSafeReleaseNULL(ivars->m_rxQueue);

    // reset SPI pointer from OS
    ivars->m_spi = nullptr;

    // Remove our memory descriptors
    OSSafeReleaseNULL(ivars->m_txqbmd);
    OSSafeReleaseNULL(ivars->m_rxqbmd);

    // reset our TX/RX segments
    ivars->m_txseg = {};
    ivars->m_rxseg = {};

    // Reset modem status
    ivars->m_hwStatus.dcd = false;
    ivars->m_hwStatus.dsr = false;
    ivars->m_hwStatus.cts = false;

    // Unlock thread
    VSPUnlock(ivars);

    ret = DisconnectQueues(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::DisconnectQueues: failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// NotifyRXReady_Impl(OSAction* action)
// Called by timer dispatch queue source
void IMPL(VSPSerialPort, NotifyRXReady)
{
    VSPLog(LOG_PREFIX, "NotifyRXReady called.\n");
    
    // Make sure action object is valid
    if (!action) {
        VSPLog(LOG_PREFIX, "NotifyRXReady bad argument. action=0%llx\n", (uint64_t) action);
        return;
    }
    
    // Notify IOUserSerial rx data ready to dispatch
    this->RxDataAvailable_Impl();
}

// --------------------------------------------------------------------
// RxEchoAsyncEvent_Impl(OSAction* action)
// Called by RX data available dispatch queue source
void IMPL(VSPSerialPort, RxEchoAsyncEvent)
{
    IOReturn ret;
    uint64_t address;

    // Lock to ensure thread safety
    VSPAquireLock(ivars);

    // skip if complete...
    // RxEchoAsyncEvent is called twice by OS
    if (!ivars->m_rxSource->IsDataAvailable()) {
        //VSPLog(LOG_PREFIX, "RxEchoAsyncEvent RX source is empty, done.\n");
        goto finish;
    }

    VSPLog(LOG_PREFIX, "++++++++++++++++++++++++++++++++++++++++\n");
    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: called.\n");

    // Make sure action object is valid
    if (!action) {
        VSPLog(LOG_PREFIX, "RxEchoAsyncEvent bad argument. action=0%llx\n", (uint64_t) action);
        goto finish;
    }

    // Lock RX dispatch queue source
    if ((ret = ivars->m_rxSource->SetEnable(false)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: RX source SetEnable false failed. code=%d\n", ret);
        goto finish;
    }

    // Update modem status
    ivars->m_hwStatus.cts = false;
    ivars->m_hwStatus.dsr = false;

    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: [IOSPI-RX 1] rxPI=%d rxCI=%d rxqoffset=%d rxqlogsz=%d\n",
           ivars->m_spi->rxPI, ivars->m_spi->rxCI, ivars->m_spi->rxqoffset, ivars->m_spi->rxqlogsz);
  
    // reset [!! 1 !!]
    // We start always our response from beginning
    // of the memory descriptor buffer
    ivars->m_spi->rxPI = 0;
    ivars->m_spi->rxCI = 0;

    // Get address to the RX ring buffer
    address = ivars->m_rxseg.address + ivars->m_spi->rxPI;
    ivars->m_rxstate.buffer = reinterpret_cast(address);
    ivars->m_rxstate.length = 0;
    
    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: dequeue RX source\n");

    // Remove queue entry from RX queue source
    ret = ivars->m_rxSource->Dequeue(^(const void *data, size_t dataSize) {
        VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: dequeue data=0x%llx size=%ld\n", (uint64_t) data, dataSize);
        // Copy data from RX queue source to RX-MD buffer
        memcpy(ivars->m_rxstate.buffer, data, dataSize);
        // Save transfered data size
        ivars->m_rxstate.length = (uint32_t) dataSize;
    });
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: RX dequeue failed. code=%d\n", ret);
        switch (ret) {
            case kIOReturnUnderrun:
                VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: ^^-> underrun\n");
                break;
            case kIOReturnError:
                VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: ^^-> corrupt\n");
                break;
        }
        goto finish;
    }
    
    // Notify queue entry has been removed
    ivars->m_rxSource->SendDataServiced();

#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: Dump m_rxqmd buffer=0x%llx size=%u\n",
           (uint64_t) ivars->m_rxstate.buffer, ivars->m_rxstate.length);

    for (uint64_t i = 0; i < ivars->m_rxstate.length; i++) {
       VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: buffer[%02lld]=0x%02x %c\n", i,
              ivars->m_rxstate.buffer[i], ivars->m_rxstate.buffer[i]);
    }
#endif

    // Unlock RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(true)) != kIOReturnSuccess) {
       VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: RX source SetEnable true failed. code=%d\n", ret);
       goto finish;
    }

    // Update RX producer index
    ivars->m_spi->rxPI = ivars->m_rxstate.length;

    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: [IOSPI-RX 2] rxPI=%d rxCI=%d rxqoffset=%d rxqlogsz=%d\n",
           ivars->m_spi->rxPI, ivars->m_spi->rxCI, ivars->m_spi->rxqoffset, ivars->m_spi->rxqlogsz);
    
    // Update modem status
    ivars->m_hwStatus.cts = true;
    ivars->m_hwStatus.dsr = true;
    
    // Notify OS interrest parties
    this->RxDataAvailable_Impl();
    
    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: complete.\n");
    
finish:
    VSPUnlock(ivars);
}

// --------------------------------------------------------------------
// TxDataAvailable_Impl()
// Called on TX data income
void IMPL(VSPSerialPort, TxDataAvailable)
{
    IOReturn ret;
    uint8_t* buffer;
    uint64_t address;
    size_t size;
    
    VSPLog(LOG_PREFIX, "--------------------------------------------------\n");
    VSPLog(LOG_PREFIX, "TxDataAvailable called.\n");
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);
    
    // Reset first
    ivars->m_txIsComplete = false;
    
    // We working...
    ivars->m_hwStatus.cts = false;
    ivars->m_hwStatus.dsr = false;
    
    // Show me indexes be fore manipulate
    VSPLog(LOG_PREFIX, "TxDataAvailable: [IOSPI-TX 1] txPI: %d, txCI: %d, txqoffset: %d, txqlogsz: %d",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);
    
    // skip if nothing to do
    if (!ivars->m_spi->txPI) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: spi->txPI is zero, skip\n");
        goto finish;
    }
   
    // Calculate available data in TX buffer
    size = ivars->m_spi->txPI - ivars->m_spi->txCI;
    
    // Get address of new TX data position
    address = ivars->m_txseg.address + ivars->m_spi->txCI;
    buffer = reinterpret_cast(address);

#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "TxDataAvailable: dump buffer=0x%llx len=%ld\n", (uint64_t) buffer, size);

    for (uint64_t i = 0; i < size; i++) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: buffer[%02lld]=0x%02x %c\n", i, buffer[i], buffer[i]);
    }
#endif

    // Show me indexes be fore manipulation
    VSPLog(LOG_PREFIX, "TxDataAvailable: [IOSPI-TX 2] txPI: %d, txCI: %d, txqoffset: %d, txqlogsz: %d",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);

    // Loopback TX data by async response event
    if ((ret = this->enqueueResponse(buffer, size)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: Unable to enqueue response. code=%d\n", ret);
        goto finish;
    }

    // Reset TX consumer index to end of received block
    ivars->m_spi->txCI = ivars->m_spi->txPI;
    
    // TX -> RX echo done
    ivars->m_txIsComplete = true;

    VSPLog(LOG_PREFIX, "TxDataAvailable complete.\n");
    
finish:
    VSPUnlock(ivars);
}

// --------------------------------------------------------------------
// Enque given buffer in RX dispatch source and raise async event
// Enqueue given buffer into RX dispatch queue source
kern_return_t VSPSerialPort::enqueueResponse(void* buffer, uint64_t size)
{
    IOReturn ret = 0;

    VSPLog(LOG_PREFIX, "enqueueResponse called.\n");

    // Make sure everything is fine
    if (!ivars || !ivars->m_rxSource || !buffer || !size) {
        VSPLog(LOG_PREFIX, "enqueueResponse: Invalid arguments\n");
        return kIOReturnBadArgument;
    }
    
    // Disable dispatching on RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(false)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX source disable failed. code=%d\n", ret);
        return ret;
    }

    // Response by adding queue entry to RX queue source
    ret = ivars->m_rxSource->Enqueue((uint32_t) size, ^(void *data, size_t dataSize) {
        VSPLog(LOG_PREFIX, "enqueueResponse: enqueue data=0x%llx size=%lld\n", (uint64_t) data, size);
        if (dataSize < size) {
            memset(data, 0xff, dataSize);
            return;
        }
        memset(data, 0,      size);
        memcpy(data, buffer, size);
    });
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX enqueue failed. code=%d\n", ret);
        switch (ret) {
            case kIOReturnOverrun:
                VSPLog(LOG_PREFIX, "enqueueResponse: ^^-> overrun\n");
                break;
            case kIOReturnError:
                VSPLog(LOG_PREFIX, "enqueueResponse: ^^-> corrupt\n");
                break;
        }
        // Leave dispatch disabled (??)
        return ret;
    }
    
    // Enable dispatching on RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(true)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX source enable failed. code=%d\n", ret);
        return ret;
    }

    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// RxDataAvailable_Impl()
// Notify OS response RX data ready for client
void IMPL(VSPSerialPort, RxDataAvailable)
{
    VSPLog(LOG_PREFIX, "RxDataAvailable called.\n");
    RxDataAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// RxFreeSpaceAvailable_Impl()
// Notification to this instance that RX buffer space is available for
// your device’s data
void IMPL(VSPSerialPort, RxFreeSpaceAvailable)
{
    VSPLog(LOG_PREFIX, "RxFreeSpaceAvailable called.\n");

    VSPAquireLock(ivars);
    VSPLog(LOG_PREFIX, "RxFreeSpaceAvailable> IOSPI rxPI=%d rxCI=%d rxqoffset=%d rxqlogsz=%d\n",
           ivars->m_spi->rxPI, ivars->m_spi->rxCI, ivars->m_spi->rxqoffset, ivars->m_spi->rxqlogsz);
    ivars->m_spi->rxPI = 0;
    ivars->m_spi->rxCI = 0;
    VSPUnlock(ivars);

    RxFreeSpaceAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// TxFreeSpaceAvailable_Impl()
// Notify OS ready for more client data
void IMPL(VSPSerialPort, TxFreeSpaceAvailable)
{
    VSPLog(LOG_PREFIX, "TxFreeSpaceAvailable called.\n");

    VSPAquireLock(ivars);
    VSPLog(LOG_PREFIX, "RxFreeSpaceAvailable> IOSPI txPI=%d txCI=%d txqoffset=%d txqlogsz=%d\n",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);
    ivars->m_spi->txPI = 0;
    ivars->m_spi->txCI = 0;
    VSPUnlock(ivars);

    TxFreeSpaceAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// SetModemStatus_Impl(bool cts, bool dsr, bool ri, bool dcd)
// Called during serial port setup or communication
kern_return_t IMPL(VSPSerialPort, SetModemStatus)
{
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "SetModemStatus called [in] CTS=%d DSR=%d RI=%d DCD=%d\n",
               cts, dsr, ri, dcd);
    
    VSPAquireLock(ivars);
    ivars->m_hwStatus.cts = cts;
    ivars->m_hwStatus.dsr = dsr;
    ivars->m_hwStatus.ri  = ri;
    ivars->m_hwStatus.dcd = dcd;
    VSPUnlock(ivars);
    
    ret = SetModemStatus(cts, dsr, ri, dcd, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::SetModemStatus failed. code=%d\n", ret);
        return ret;
    }

    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// RxError_Impl(bool overrun, bool break, bool framing, bool parity)
// Called on given error states
kern_return_t IMPL(VSPSerialPort, RxError)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "RxError called.\n");
    
    if (overrun) {
        VSPLog(LOG_PREFIX, "RX overrun.\n");
    }
    
    if (gotBreak) {
        VSPLog(LOG_PREFIX, "RX got break.\n");
    }
    
    if (framingError) {
        VSPLog(LOG_PREFIX, "RX framing error.\n");
    }
    
    if (parityError) {
        VSPLog(LOG_PREFIX, "RX parity error.\n");
    }
    
    VSPAquireLock(ivars);
    ivars->m_errorState.overrun = overrun;
    ivars->m_errorState.framingError = framingError;
    ivars->m_errorState.gotBreak = gotBreak;
    ivars->m_errorState.parityError = parityError;
    VSPUnlock(ivars);
    
    ret = RxError(overrun, gotBreak, framingError, parityError, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::RxError: failed. code=%d\n", ret);
        return ret;
    }

    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwActivate_Impl()
// Called after ConnectQueues() or other reasons
kern_return_t IMPL(VSPSerialPort, HwActivate)
{
    kern_return_t ret = kIOReturnIOError;
    
    VSPLog(LOG_PREFIX, "HwActivate called.\n");
    
    VSPAquireLock(ivars);
    ivars->m_hwActivated = true;
    // ???
    ivars->m_hwStatus.dcd = true;
    // ???
    ivars->m_hwStatus.cts = true;
    VSPUnlock(ivars);
    
    ret = HwActivate(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::HwActivate failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// HwDeactivate_Impl()
// Called before DisconnectQueues() or other reasons
kern_return_t IMPL(VSPSerialPort, HwDeactivate)
{
    kern_return_t ret = kIOReturnIOError;
    
    VSPLog(LOG_PREFIX, "HwDeactivate called.\n");
    
    VSPAquireLock(ivars);
    ivars->m_hwActivated = false;
    // ???
    ivars->m_hwStatus.dcd = false;
    // ???
    ivars->m_hwStatus.cts = false;
    VSPUnlock(ivars);
    
    ret = HwDeactivate(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::HwDeactivate failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// HwResetFIFO_Impl()
// Called by client to TxFreeSpaceAvailable or RxFreeSpaceAvailable
// or other reasons.
kern_return_t IMPL(VSPSerialPort, HwResetFIFO)
{
    VSPLog(LOG_PREFIX, "HwResetFIFO called -> tx=%d rx=%d\n",
               tx, rx);
    
    VSPAquireLock(ivars);
    // ?? notify caller (IOUserSerial)
    if (rx) {
        ivars->m_hwStatus.dsr = false;
    }
    
    // ?? notify caller (IOUserSerial)
    if (tx) {
        ivars->m_hwStatus.cts = true;
    }
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwSendBreak_Impl()
// Called during client communication life cycle
kern_return_t IMPL(VSPSerialPort, HwSendBreak)
{
    VSPLog(LOG_PREFIX, "HwSendBreak called -> sendBreak=%d\n", sendBreak);
    
    VSPAquireLock(ivars);
    ivars->m_errorState.gotBreak = sendBreak;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwGetModemStatus_Impl()
// Called during client communication life cycle
kern_return_t IMPL(VSPSerialPort, HwGetModemStatus)
{
    VSPLog(LOG_PREFIX, "HwGetModemStatus called [out] CTS=%d DSR=%d RI=%d DCD=%d\n", //
               ivars->m_hwStatus.cts, ivars->m_hwStatus.dsr, //
               ivars->m_hwStatus.ri, ivars->m_hwStatus.dcd);
    
    VSPAquireLock(ivars);
    if (cts != nullptr) {
        (*cts) = ivars->m_hwStatus.cts;
    }
    
    if (dsr != nullptr) {
        (*dsr) = ivars->m_hwStatus.dsr;
    }
    
    if (ri != nullptr) {
        (*ri) = ivars->m_hwStatus.ri;
    }
    
    if (dcd != nullptr) {
        (*dcd) = ivars->m_hwStatus.dcd;
    }
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramUART_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramUART)
{
    VSPLog(LOG_PREFIX, "HwProgramUART called -> baudRate=%d "
                        "nDataBits=%d nHalfStopBits=%d parity=%d\n",
            baudRate, nDataBits, nHalfStopBits, parity);
    
    VSPAquireLock(ivars);
    ivars->m_uartParams.baudRate = baudRate;
    ivars->m_uartParams.nDataBits = nDataBits;
    ivars->m_uartParams.nHalfStopBits = nHalfStopBits;
    ivars->m_uartParams.parity = parity;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramBaudRate_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramBaudRate)
{
    VSPLog(LOG_PREFIX, "HwProgramBaudRate called -> baudRate=%d\n", baudRate);
    
    VSPAquireLock(ivars);
    ivars->m_uartParams.baudRate = baudRate;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramMCR_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramMCR)
{
    VSPLog(LOG_PREFIX, "HwProgramMCR called -> DTR=%d RTS=%d\n",
               dtr, rts);
    
    VSPAquireLock(ivars);
    ivars->m_hwMCR.dtr = dtr;
    ivars->m_hwMCR.rts = rts;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramLatencyTimer_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramLatencyTimer)
{
    VSPLog(LOG_PREFIX, "HwProgramLatencyTimer called -> latency=%d\n",
               latency);
    
    VSPAquireLock(ivars);
    ivars->m_hwLatency = latency;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramLatencyTimer_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramFlowControl)
{
    VSPLog(LOG_PREFIX, "HwProgramFlowControl called -> arg=%02x xon=%02x xoff=%02x\n",
               arg, xon, xoff);
    
    VSPAquireLock(ivars);
    ivars->m_hwFlowControl.arg = arg;
    ivars->m_hwFlowControl.xon = xon;
    ivars->m_hwFlowControl.xoff = xoff;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Called by VSPDriver instance to link to parent level
//
void VSPSerialPort::setParent(VSPDriver* parent)
{
    VSPLog(LOG_PREFIX, "setParent called.\n");

    if (ivars != nullptr && !ivars->m_parent) {
        ivars->m_parent = parent;
    }
}

// --------------------------------------------------------------------
// Called by VSPDriver instance to set TTY base and number based on
// managed instance of this object instance
kern_return_t VSPSerialPort::setupTTYBaseName()
{
    IOReturn ret;
    OSDictionary* properties = nullptr;
    OSString* baseName = nullptr;
 
    VSPLog(LOG_PREFIX, "setupTTYBaseName called.\n");
    
    // setup custom TTY name
    if ((ret = CopyProperties(&properties)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "setupTTYBaseName: Unable to get properties. code=%d\n", ret);
        return ret;
    }
   
    //CreateNameMatchingDictionary(<#OSString *serviceName#>, <#OSDictionary *matching#>)
    //baseName = OSString::withCString(kVSPTTYBaseName);
    //properties->setObject(kIOTTYBaseNameKey, baseName);
    
    // write back to driver instance
    if ((ret = SetProperties(properties)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "setupTTYBaseName: Unable to set TTY base name. code=%d\n", ret);
        //return ret; // ??? an error - why???
    }
    
    OSSafeReleaseNULL(baseName);
    OSSafeReleaseNULL(properties);
    return kIOReturnSuccess;
}



// Notify RX complete to OS interrest parties
// using client defined latency time
//ret = ivars->m_tiSource->WakeAtTime(
//                                    kIOTimerClockMonotonicRaw,
//                                    clock_gettime_nsec_np(CLOCK_MONOTONIC_RAW)
//                                    + (ivars->m_hwLatency * 1000000),
//                                    1000000000);
//if (ret != kIOReturnSuccess) {
//    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: tiSource WakeAtTime failed. code=%d\n", ret);
//    goto finish;
//}
GitHub Project

Attached is the running/working code, but finally the DEX crash ;-)

Best Regards

Ok, the problem with the buffer overrun has been fixed :) Is a dirty? solution:

// --------------------------------------------------------------
// TxDataAvailable_Impl()
// TX data ready to read from m_txqbmd segment
void IMPL(VSPSerialPort, TxDataAvailable)
{
    IOReturn ret;
    uint8_t* buffer;
    uint64_t address;
    uint32_t size;
    bool needReset = false;

    VSPLog(LOG_PREFIX, "----------------------------------\n");
    VSPLog(LOG_PREFIX, "TxDataAvailable called.\n");
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);
    
    // Reset first
    ivars->m_txIsComplete = false;
    
    // We working...
    ivars->m_hwStatus.cts = false;
    ivars->m_hwStatus.dsr = false;
    
    // Show me indexes be fore manipulate
    VSPLog(LOG_PREFIX, "TxDataAvailable: [IOSPI-TX 1] txPI: %d, txCI: %d, txqoffset: %d, txqlogsz: %d",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);
    
    // skip if nothing to do
    if (!ivars->m_spi->txPI) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: spi->txPI is zero, skip\n");
        goto finish;
    }
 
    // Get address of new TX data position
    address = ivars->m_txseg.address + ivars->m_spi->txCI;
    buffer  = reinterpret_cast<uint8_t*>(address);

    // Calculate available data in TX buffer
    size = ivars->m_spi->txPI - ivars->m_spi->txCI;
    
#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "TxDataAvailable: dump buffer=0x%llx len=%u\n", (uint64_t) buffer, size);

    for (uint64_t i = 0; i < size; i++) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: buffer[%02lld]=0x%02x %c\n", i, buffer[i], buffer[i]);
    }
#endif

    // Loopback TX data by async response event
    if ((ret = this->enqueueResponse(buffer, size)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: Unable to enqueue response. code=%d\n", ret);
        goto finish;
    }

    // TX -> RX echo done
    ivars->m_txIsComplete = true;

    // We reserve 1K size from the capacity from t_txqbmd. This protects
    // against a buffer overflow.
    if ((ivars->m_spi->txPI + 1024) >= (ivars->m_txseg.length - 1024)) {
        ivars->m_spi->txPI = 0;
        ivars->m_spi->txCI = 0;
    }
    // Reset TX consumer index to end of received block. This increases the
    // offset for the m_txqbmd buffer. Finally the DEXT crash if to protection.
    // Reset values like txPI = 0 and txCI = 0 after some transmissions.
    else {
        ivars->m_spi->txCI = ivars->m_spi->txPI;
    }
    
    // Show me indexes be fore manipulation
    VSPLog(LOG_PREFIX, "TxDataAvailable: [IOSPI-TX 2] txPI: %d, txCI: %d, txqoffset: %d, txqlogsz: %d",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);

    // reset memory
    memset(buffer, 0, size);

    VSPLog(LOG_PREFIX, "TxDataAvailable complete.\n");
    
finish:
    VSPUnlock(ivars);
}

Hello Keven, the serial port driver extension executes a local echo. This works well so far. In the top instance (VSPDriver) there is a mechanism that connects two serial ports to each other. In the serial port instance (VSPSerialPort) in the method 'RxEchoAsyncEvent' it is checked whether a link exists. If so, then the TX packet should be transmitted as an echo to the other serial port as RX. According to the following pattern: Port1-TX -> Port2-RX. My problem: If I fill the Port2 RX-IOMemoryDescriptor (Buffer) with the data from Port1-TX, only one character is displayed in the terminal. No further data arrives on the terminal that is connected to Port2. Now the all-important $1 million question: What else needs to be done so that Port2 continuously sends the data to the client (e.g. Serial IO Terminal)?

The workflow Port1-TX -> TxDataAvailable() -> Enque data and dispatch async -> Same Port1 object instance gets IODataQueueDispatchSource::DataAvailable event (RxEchoAsyncEvent) -> This method then calls Port2-RX 'sendResponse' and fills the buffer of rxqmd and updates the fields in the SerialPortInterface of Port2-RX accordingly.

Best regards

// ********************************************************************
// VSPSerialPort - Serial port implementation
//
// Copyright © 2025 by EoF Software Labs
// Copyright © 2024 Apple Inc. (some copied parts)
// SPDX-License-Identifier: MIT
// ********************************************************************

// -- OS
#include 
#include 
#include 
#include 

#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 

#include 
#include 
#include 

// -- SerialDriverKit
#include 
#include 
#include 
using namespace driverkit::serial;

// -- My
#include "VSPSerialPort.h"
#include "VSPController.h"
#include "VSPLogger.h"
#include "VSPDriver.h"

#define LOG_PREFIX "VSPSerialPort"

#define kVSPTTYBaseName "vsp"
#define kRxDataQueueName "rxDataQueue"

#ifndef IOLockFreeNULL
#define IOLockFreeNULL(l) { if (NULL != (l)) { IOLockFree(l); (l) = NULL; } }
#endif

#define VSPAquireLock(ivars) \
{ \
++ivars->m_lockLevel; \
VSPLog(LOG_PREFIX, "=> lock level=%d", ivars->m_lockLevel); \
IOLockLock(ivars->m_lock); \
}

#define VSPUnlock(ivars) \
{ \
VSPLog(LOG_PREFIX, "<= lock level=%d", ivars->m_lockLevel); \
--ivars->m_lockLevel; \
IOLockUnlock(ivars->m_lock); \
}

// Updated by SetModemStatus read by HwGetModemStatus
typedef struct {
    bool cts;
    bool dsr;
    bool ri;
    bool dcd;
} THwSerialStatus;

// Updated by HwProgramFlowControl
typedef struct{
    uint32_t arg;
    uint8_t xon;
    uint8_t xoff;
} THwFlowControl;

// Updated by HwProgramMCR
typedef struct {
    bool dtr;
    bool rts;
} THwMCR;

// Updated by HwProgramUART and HwProgramBaudRate
typedef struct {
    uint32_t baudRate;
    uint8_t nDataBits;
    uint8_t nHalfStopBits;
    uint8_t parity;
} TUartParameters;

// Updated by RxError and HwSendBreak
typedef struct {
    bool overrun;
    bool gotBreak;
    bool framingError;
    bool parityError;
} TErrorState;

typedef struct {
    uint8_t* buffer;
    uint32_t length;
} TRXBufferState;

// Driver instance state resource
struct VSPSerialPort_IVars {
    IOService* m_provider = nullptr;
    VSPDriver* m_parent = nullptr;                  // VSPDriver instance
    
    uint8_t m_portId = 0;                           // port id given by VSPDriver
    uint8_t m_portLinkId = 0;                       // port link id given by VSPDriver
    
    IOLock* m_lock = nullptr;                       // for resource locking
    volatile atomic_int m_lockLevel = 0;
    
    /* OS provided memory descriptors by overridden
     * method ConnectQueues(...) */
    SerialPortInterface* m_spi;                     // OS serial port interface
    
    IOBufferMemoryDescriptor* m_txqbmd;             // VSP TX queue memory descriptor
    IOAddressSegment m_txseg = {};                  // VSP TX buffer segment
    
    IOBufferMemoryDescriptor* m_rxqbmd;             // VSP RX queue memory descriptor
    IOAddressSegment m_rxseg = {};                  // VSP RX buffer segment
    
    TRXBufferState m_rxstate = {};                  // RX dequeue data
    
    // Timed events
    IODispatchQueue* m_tiQueue = nullptr;
    IOTimerDispatchSource* m_tiSource = nullptr;
    OSAction* m_tiAction = nullptr;
    OSData* m_tiData = nullptr;
    
    // Response buffer created by TxAvailable()
    IODispatchQueue* m_rxQueue = nullptr;
    IODataQueueDispatchSource* m_rxSource = nullptr;
    OSAction* m_rxAction = nullptr;
    
    // Serial interface
    TErrorState m_errorState = {};
    TUartParameters m_uartParams = {};
    THwSerialStatus m_hwStatus = {};
    THwFlowControl m_hwFlowControl = {};
    THwMCR m_hwMCR = {};
    uint32_t m_hwLatency = 25;
    bool m_txNextOffset = 0;
    bool m_txIsComplete = false;
    bool m_rxIsComplete = false;
    bool m_hwActivated = false;
};

// --------------------------------------------------------------------
// Allocate internal resources
//
bool VSPSerialPort::init(void)
{
    bool result;
    
    VSPLog(LOG_PREFIX, "init called.\n");
    
    if (!(result = super::init())) {
        VSPLog(LOG_PREFIX, "super::init falsed. result=%d\n", result);
        goto error_exit;
    }
    
    // Create instance state resource
    ivars = IONewZero(VSPSerialPort_IVars, 1);
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Unable to allocate driver data.\n");
        result = false;
        goto error_exit;
    }
    
    VSPLog(LOG_PREFIX, "init finished.\n");
    return true;
    
error_exit:
    return result;
}

// --------------------------------------------------------------------
// Release internal resources
//
void VSPSerialPort::free(void)
{
    VSPLog(LOG_PREFIX, "free called.\n");
    
    // Release instance state resource
    IOSafeDeleteNULL(ivars, VSPSerialPort_IVars, 1);
    super::free();
}

// --------------------------------------------------------------------
// Start_Impl(IOService* provider)
//
kern_return_t IMPL(VSPSerialPort, Start)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Start: called.\n");
    
    // sane check our driver instance vars
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Start: Private driver instance is NULL\n");
        return kIOReturnInvalid;
    }
    
    // call super method (apple style)
    ret = Start(provider, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start(super): failed. code=%d\n", ret);
        return ret;
    }
    
    // remember OS provider
    ivars->m_provider = provider;
    
    // the resource locker
    ivars->m_lock = IOLockAlloc();
    if (ivars->m_lock == nullptr) {
        VSPLog(LOG_PREFIX, "Start: Unable to allocate lock object.\n");
        goto error_exit;
    }
    
    // create our own TTY name and index
    if ((ret = setupTTYBaseName()) != kIOReturnSuccess) {
        goto error_exit;
    }
    
    // default UART parameters
    ivars->m_uartParams.baudRate = 112500;
    ivars->m_uartParams.nHalfStopBits = 2;
    ivars->m_uartParams.nDataBits = 8;
    ivars->m_uartParams.parity = 0;
    
    VSPLog(LOG_PREFIX, "Start: Allocate timer queue and resources.\n");
    
    ret = IODispatchQueue::Create("kVSPTimerQueue", 0, 0, &ivars->m_tiQueue);
    if (ret != kIOReturnSuccess || !ivars->m_tiQueue) {
        VSPLog(LOG_PREFIX, "Start: Unable to create timer queue. code=%d\n", ret);
        goto error_exit;
    }
    
    ret = IOTimerDispatchSource::Create(ivars->m_tiQueue, &ivars->m_tiSource);
    if (ret != kIOReturnSuccess || !ivars->m_tiSource) {
        VSPLog(LOG_PREFIX, "Start: Unable to create timer queue. code=%d\n", ret);
        goto error_exit;
    }
    
    ret = CreateActionNotifyRXReady(sizeof(ivars->m_tiData), &ivars->m_tiAction);
    if (ret != kIOReturnSuccess || !ivars->m_tiAction) {
        VSPLog(LOG_PREFIX, "Start: Unable to timer callback action. code=%d\n", ret);
        goto error_exit;
    }
    
    ret = ivars->m_tiSource->SetHandler(ivars->m_tiAction);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: Unable to assign timer action. code=%d\n", ret);
        goto error_exit;
    }
    
    VSPLog(LOG_PREFIX, "Start: register service.\n");
    
    // Register driver instance to IOReg
    if ((ret = RegisterService()) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: RegisterService failed. code=%d\n", ret);
        goto error_exit;
    }
    
    VSPLog(LOG_PREFIX, "Start: driver started successfully.\n");
    return kIOReturnSuccess;
    
error_exit:
    cleanupResources();
    Stop(provider, SUPERDISPATCH);
    return ret;
}

// --------------------------------------------------------------------
// Stop_Impl(IOService* provider)
//
kern_return_t IMPL(VSPSerialPort, Stop)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Stop called.\n");
    
    // Unlink VSP parent
    ivars->m_parent = nullptr;
    
    // Remove all IVars resources
    cleanupResources();
    
    /* Shutdown instane */
    if ((ret= Stop(provider, SUPERDISPATCH)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::Stop failed. code=%d\n", ret);
    } else {
        VSPLog(LOG_PREFIX, "driver successfully removed.\n");
    }
    
    return ret;
}

// --------------------------------------------------------------------
// Remove all resources in IVars
//
void VSPSerialPort::cleanupResources()
{
    VSPLog(LOG_PREFIX, "cleanupResources called.\n");
    
    OSSafeReleaseNULL(ivars->m_tiQueue);
    OSSafeReleaseNULL(ivars->m_tiSource);
    OSSafeReleaseNULL(ivars->m_tiAction);
    OSSafeReleaseNULL(ivars->m_tiData);
    
    IOLockFreeNULL(ivars->m_lock);
}

// ====================================================================
// ** ----------------[ Connection live cycle&nbsp;]--------------------- **
// ====================================================================

// --------------------------------------------------------------------
// ConnectQueues_Impl( ... )
// First call
kern_return_t IMPL(VSPSerialPort, ConnectQueues)
{
    IOAddressSegment ifseg = {};
    size_t txcapacity, rxcapacity;
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "ConnectQueues called\n");
    
    //-- Sane check --//
    if (!in_txqlogsz || !in_rxqlogsz) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid in_rxqlogsz or in_txqlogsz detected.\n");
        return kIOReturnBadArgument;
    }
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);
    
    // Convert the base-2 logarithmic size of the buffer or the in_txqmd parameter.
    txcapacity = (size_t) ::pow(2, in_txqlogsz);
    ret = IOBufferMemoryDescriptor::Create(kIOMemoryDirectionIn, txcapacity, 0, &ivars->m_txqbmd);
    if (ret != kIOReturnSuccess || !ivars->m_txqbmd) {
        VSPLog(LOG_PREFIX, "Start: Unable to create TX memory descriptor. code=%d\n", ret);
        goto error_exit;
    }
    
    // Convert the base-2 logarithmic size of the buffer for the in_rxqmd parameter.
    rxcapacity = (size_t) ::pow(2, in_rxqlogsz);
    ret = IOBufferMemoryDescriptor::Create(kIOMemoryDirectionOut, rxcapacity, 0, &ivars->m_rxqbmd);
    if (ret != kIOReturnSuccess || !ivars->m_rxqbmd) {
        VSPLog(LOG_PREFIX, "Start: Unable to create RX memory descriptor. code=%d\n", ret);
        goto error_exit;
    }
    
    // make sure the parameters are zero
    in_rxqoffset = 0;
    in_txqoffset = 0;
    
    // Call super to get SerialPortInterface and set our RX/TX memory descriptors
    ret = ConnectQueues(ifmd, rxqmd, txqmd,
                        ivars->m_rxqbmd,
                        ivars->m_txqbmd,
                        in_rxqoffset,
                        in_txqoffset,
                        in_rxqlogsz,
                        in_txqlogsz, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::ConnectQueues failed. code=%d\n", ret);
        goto error_exit;
    }
    
    //-- Sane check --//
    if (!ifmd || !(*ifmd) || !txqmd || !(*txqmd) || !rxqmd || !(*rxqmd)) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid memory descriptors detected. (NULL)\n");
        ret = kIOReturnBadArgument;
        goto error_exit;
    }
    if ((*txqmd) != ivars->m_txqbmd) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'txqmd' memory descriptor detected.\n");
        ret = kIOReturnInvalid;
        goto error_exit;
    }
    if ((*rxqmd) != ivars->m_rxqbmd) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Invalid 'rxqmd' memory descriptor detected.\n");
        ret = kIOReturnInvalid;
        goto error_exit;
    }
    
    // Get the address of the TX memory descriptor
    ret = ivars->m_txqbmd->GetAddressRange(&ivars->m_txseg);
    if (ret != kIOReturnSuccess || !ivars->m_txseg.address || ivars->m_txseg.length != txcapacity) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to get TX-MD segment. code=%d\n", ret);
        goto error_exit;
    }
    
    // Get the address of the RX memory descriptor
    ret = ivars->m_rxqbmd->GetAddressRange(&ivars->m_rxseg);
    if (ret != kIOReturnSuccess || !ivars->m_rxseg.address || ivars->m_rxseg.length != rxcapacity) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to get TX-MD segment. code=%d\n", ret);
        goto error_exit;
    }
    
    // Get the address of the IOSerialPortInterface segment (mapped space)
    if ((ret = (*ifmd)->GetAddressRange(&ifseg)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "ConnectQueues: IF GetAddressRange failed. code=%d\n", ret);
        goto error_exit;
    }
    
    // Initialize the indexes
    ivars->m_spi = reinterpret_cast(ifseg.address);
    ivars->m_spi->txCI = 0;
    ivars->m_spi->txPI = 0;
    
    // -- Setup RX response queue and dispatch source --
    
    // 0 = No options are currently defined.
    // 0 = No priorities are currently defined.
    ret = IODispatchQueue::Create(kRxDataQueueName, 0, 0, &ivars->m_rxQueue);
    if (ret != kIOReturnSuccess || !ivars->m_rxQueue) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to create RX queue. code=%d\n", ret);
        goto error_exit;
    }
    
    ret = IODataQueueDispatchSource::Create(ivars->m_rxseg.length, ivars->m_rxQueue, &ivars->m_rxSource);
    if (ret != kIOReturnSuccess || !ivars->m_rxSource) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to creade dispatch soure. code=%d\n", ret);
        goto error_exit;
    }
    
    // Async notification from IODataQueueDispatchSource::DataAvailable
    ret = CreateActionRxEchoAsyncEvent(ivars->m_rxseg.length, &ivars->m_rxAction);
    if (ret != kIOReturnSuccess || !ivars->m_rxAction) {
        VSPLog(LOG_PREFIX, "ConnectQueues: Unable to create RX action. code=%d\n", ret);
        goto error_exit;
    }
    
    // Set async async callback action
    ret = ivars->m_rxSource->SetDataAvailableHandler(ivars->m_rxAction);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "ConnectQueues: SetDataAvailableHandler failed. code=%d\n", ret);
        goto error_exit;
    }
    
    // Modem is ready
    ivars->m_hwStatus.dcd = true;
    ivars->m_hwStatus.cts = true;
    
    VSPUnlock(ivars);
    return kIOReturnSuccess;
    
error_exit:
    OSSafeReleaseNULL(ivars->m_txqbmd);
    OSSafeReleaseNULL(ivars->m_rxqbmd);
    OSSafeReleaseNULL(ivars->m_rxAction);
    OSSafeReleaseNULL(ivars->m_rxSource);
    OSSafeReleaseNULL(ivars->m_rxQueue);
    VSPUnlock(ivars);
    return ret;
}

// --------------------------------------------------------------------
// DisconnectQueues_Impl()
// Last call
kern_return_t IMPL(VSPSerialPort, DisconnectQueues)
{
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "DisconnectQueues called\n");
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);
    
    // stop RX dispatch queue
    OSSafeReleaseNULL(ivars->m_rxSource);
    OSSafeReleaseNULL(ivars->m_rxAction);
    OSSafeReleaseNULL(ivars->m_rxQueue);
    
    // reset SPI pointer from OS
    ivars->m_spi = nullptr;
    
    // Remove our memory descriptors
    OSSafeReleaseNULL(ivars->m_txqbmd);
    OSSafeReleaseNULL(ivars->m_rxqbmd);
    
    // reset our TX/RX segments
    ivars->m_txseg = {};
    ivars->m_rxseg = {};
    
    // Reset modem status
    ivars->m_hwStatus.dcd = false;
    ivars->m_hwStatus.dsr = false;
    ivars->m_hwStatus.cts = false;
    
    // Unlock thread
    VSPUnlock(ivars);
    
    ret = DisconnectQueues(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::DisconnectQueues: failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// NotifyRXReady_Impl(OSAction* action)
// Called by timer dispatch queue source
void IMPL(VSPSerialPort, NotifyRXReady)
{
    VSPLog(LOG_PREFIX, "NotifyRXReady called.\n");
    
    // Make sure action object is valid
    if (!action) {
        VSPLog(LOG_PREFIX, "NotifyRXReady bad argument. action=0%llx\n", (uint64_t) action);
        return;
    }
    
    // Notify IOUserSerial rx data ready to dispatch
    this->RxDataAvailable_Impl();
}

// --------------------------------------------------------------------
// RxEchoAsyncEvent_Impl(OSAction* action)
// Called by RX data available dispatch queue source
void IMPL(VSPSerialPort, RxEchoAsyncEvent)
{
    IODataQueueDispatchSource* source;
    IOReturn ret;
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);
    
    // skip if complete...
    // RxEchoAsyncEvent is called twice by OS
    if (!ivars->m_rxSource->IsDataAvailable()) {
        //VSPLog(LOG_PREFIX, "RxEchoAsyncEvent RX source is empty, done.\n");
        goto finish;
    }
    
    VSPLog(LOG_PREFIX, "++++++++++++++++++++++++++++++++++++++++\n");
    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: called.\n");
    
    // Make sure action object is valid
    if (!action) {
        VSPLog(LOG_PREFIX, "RxEchoAsyncEvent bad argument. action=0%llx\n", (uint64_t) action);
        goto finish;
    }
  
    // This port is assigned to a port link?
    if (ivars->m_portLinkId) {
        // source for other port instance
        source = ivars->m_rxSource;
        // sendToPortLink lock also
        VSPUnlock(ivars);
        // send to other port instance
        if ((ret = sendToPortLink(source)) != kIOReturnSuccess) {
            VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: Data routing failed. code=%d\n", ret);
        }
        return;
     }

    // set my own RX source
    source = ivars->m_rxSource;
    // sendResponse lock also
    VSPUnlock(ivars);
    // echo to my self...
    sendResponse(source);
    // no double unlock :)
    return;
    
finish:
    VSPUnlock(ivars);
}

// --------------------------------------------------------------------
// TxDataAvailable_Impl()
// TX data ready to read from m_txqbmd segment
void IMPL(VSPSerialPort, TxDataAvailable)
{
    IOReturn ret;
    uint8_t* buffer;
    uint64_t address;
    uint32_t size;
    
    VSPLog(LOG_PREFIX, "--------------------------------------------------\n");
    VSPLog(LOG_PREFIX, "TxDataAvailable called.\n");
    
    // Lock to ensure thread safety
    VSPAquireLock(ivars);
    
    // Reset first
    ivars->m_txIsComplete = false;
    
    // We working...
    ivars->m_hwStatus.cts = false;
    ivars->m_hwStatus.dsr = false;
    
    // Show me indexes be fore manipulate
    VSPLog(LOG_PREFIX, "TxDataAvailable: [IOSPI-TX 1] txPI: %d, txCI: %d, txqoffset: %d, txqlogsz: %d",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);
    
    // skip if nothing to do
    if (!ivars->m_spi->txPI) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: spi->txPI is zero, skip\n");
        goto finish;
    }
    
    // Get address of new TX data position
    address = ivars->m_txseg.address + ivars->m_spi->txCI;
    buffer  = reinterpret_cast(address);
    
    // Calculate available data in TX buffer
    size = ivars->m_spi->txPI - ivars->m_spi->txCI;
    
#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "TxDataAvailable: dump buffer=0x%llx len=%u\n", (uint64_t) buffer, size);
    
    for (uint64_t i = 0; i < size; i++) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: buffer[%02lld]=0x%02x %c\n", i, buffer[i], buffer[i]);
    }
#endif
    
    // Loopback TX data by async response event
    if ((ret = this->enqueueResponse(buffer, size)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "TxDataAvailable: Unable to enqueue response. code=%d\n", ret);
        goto finish;
    }
    
    // TX -> RX echo done
    ivars->m_txIsComplete = true;
    
    // We reserve 1K size from the capacity from t_txqbmd.
    // This protects against a buffer overflow.
    if (((uint32_t) ivars->m_txseg.length - ivars->m_spi->txPI) < 1024) {
        ivars->m_spi->txPI = 0;
        ivars->m_spi->txCI = 0;
    }
    // Reset TX consumer index to end of received block. This increases the
    // offset for the m_txqbmd buffer. Finally the DEXT crash if to protection.
    // Reset values like txPI = 0 and txCI = 0 after some transmissions.
    else {
        ivars->m_spi->txCI = ivars->m_spi->txPI;
    }
    
    // Show me indexes be fore manipulation
    VSPLog(LOG_PREFIX, "TxDataAvailable: [IOSPI-TX 2] txPI: %d, txCI: %d, txqoffset: %d, txqlogsz: %d",
           ivars->m_spi->txPI, ivars->m_spi->txCI, ivars->m_spi->txqoffset, ivars->m_spi->txqlogsz);
    
    // reset memory
    memset(buffer, 0, size);
    
    VSPLog(LOG_PREFIX, "TxDataAvailable complete.\n");
    
finish:
    VSPUnlock(ivars);
}

// --------------------------------------------------------------------
// Enque given buffer in RX dispatch source and raise async event
// Enqueue given buffer into RX dispatch queue source
kern_return_t VSPSerialPort::enqueueResponse(void* buffer, uint64_t size)
{
    IOReturn ret = 0;
    
    VSPLog(LOG_PREFIX, "enqueueResponse called.\n");
    
    // Make sure everything is fine
    if (!ivars || !ivars->m_rxSource || !buffer || !size) {
        VSPLog(LOG_PREFIX, "enqueueResponse: Invalid arguments\n");
        return kIOReturnBadArgument;
    }
    
    // Disable dispatching on RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(false)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX source disable failed. code=%d\n", ret);
        return ret;
    }
    
    // Response by adding queue entry to RX queue source
    ret = ivars->m_rxSource->Enqueue((uint32_t) size, ^(void *data, size_t dataSize) {
        VSPLog(LOG_PREFIX, "enqueueResponse: enqueue data=0x%llx size=%lld\n", (uint64_t) data, size);
        if (dataSize < size) {
            memset(data, 0xff, dataSize);
            return;
        }
        memset(data, 0,      size);
        memcpy(data, buffer, size);
    });
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX enqueue failed. code=%d\n", ret);
        switch (ret) {
            case kIOReturnOverrun:
                VSPLog(LOG_PREFIX, "enqueueResponse: ^^-> overrun\n");
                break;
            case kIOReturnError:
                VSPLog(LOG_PREFIX, "enqueueResponse: ^^-> corrupt\n");
                break;
        }
        // Leave dispatch disabled (??)
        return ret;
    }
    
    // Enable dispatching on RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(true)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enqueueResponse: RX source enable failed. code=%d\n", ret);
        return ret;
    }
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// RxDataAvailable_Impl()
// Notify OS response RX data ready for client
void IMPL(VSPSerialPort, RxDataAvailable)
{
    VSPLog(LOG_PREFIX, "RxDataAvailable called.\n");
    RxDataAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// RxFreeSpaceAvailable_Impl()
// Notification to this instance that RX buffer space is available for
// your device’s data
void IMPL(VSPSerialPort, RxFreeSpaceAvailable)
{
    VSPLog(LOG_PREFIX, "RxFreeSpaceAvailable called.\n");
    RxFreeSpaceAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// TxFreeSpaceAvailable_Impl()
// Notify OS ready for more client data
void IMPL(VSPSerialPort, TxFreeSpaceAvailable)
{
    VSPLog(LOG_PREFIX, "TxFreeSpaceAvailable called.\n");
    TxFreeSpaceAvailable(SUPERDISPATCH);
}

// --------------------------------------------------------------------
// SetModemStatus_Impl(bool cts, bool dsr, bool ri, bool dcd)
// Called during serial port setup or communication
kern_return_t IMPL(VSPSerialPort, SetModemStatus)
{
    IOReturn ret;
    
    VSPLog(LOG_PREFIX, "SetModemStatus called [in] CTS=%d DSR=%d RI=%d DCD=%d\n",
           cts, dsr, ri, dcd);
    
    VSPAquireLock(ivars);
    ivars->m_hwStatus.cts = cts;
    ivars->m_hwStatus.dsr = dsr;
    ivars->m_hwStatus.ri  = ri;
    ivars->m_hwStatus.dcd = dcd;
    VSPUnlock(ivars);
    
    ret = SetModemStatus(cts, dsr, ri, dcd, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::SetModemStatus failed. code=%d\n", ret);
        return ret;
    }
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// RxError_Impl(bool overrun, bool break, bool framing, bool parity)
// Called on given error states
kern_return_t IMPL(VSPSerialPort, RxError)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "RxError called.\n");
    
    if (overrun) {
        VSPLog(LOG_PREFIX, "RX overrun.\n");
    }
    
    if (gotBreak) {
        VSPLog(LOG_PREFIX, "RX got break.\n");
    }
    
    if (framingError) {
        VSPLog(LOG_PREFIX, "RX framing error.\n");
    }
    
    if (parityError) {
        VSPLog(LOG_PREFIX, "RX parity error.\n");
    }
    
    VSPAquireLock(ivars);
    ivars->m_errorState.overrun = overrun;
    ivars->m_errorState.framingError = framingError;
    ivars->m_errorState.gotBreak = gotBreak;
    ivars->m_errorState.parityError = parityError;
    VSPUnlock(ivars);
    
    ret = RxError(overrun, gotBreak, framingError, parityError, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::RxError: failed. code=%d\n", ret);
        return ret;
    }
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwActivate_Impl()
// Called after ConnectQueues() or other reasons
kern_return_t IMPL(VSPSerialPort, HwActivate)
{
    kern_return_t ret = kIOReturnIOError;
    
    VSPLog(LOG_PREFIX, "HwActivate called.\n");
    
    VSPAquireLock(ivars);
    ivars->m_hwActivated = true;
    // ???
    ivars->m_hwStatus.dcd = true;
    // ???
    ivars->m_hwStatus.cts = true;
    VSPUnlock(ivars);
    
    ret = HwActivate(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::HwActivate failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// HwDeactivate_Impl()
// Called before DisconnectQueues() or other reasons
kern_return_t IMPL(VSPSerialPort, HwDeactivate)
{
    kern_return_t ret = kIOReturnIOError;
    
    VSPLog(LOG_PREFIX, "HwDeactivate called.\n");
    
    VSPAquireLock(ivars);
    ivars->m_hwActivated = false;
    // ???
    ivars->m_hwStatus.dcd = false;
    // ???
    ivars->m_hwStatus.cts = false;
    VSPUnlock(ivars);
    
    ret = HwDeactivate(SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "super::HwDeactivate failed. code=%d\n", ret);
        return ret;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// HwResetFIFO_Impl()
// Called by client to TxFreeSpaceAvailable or RxFreeSpaceAvailable
// or other reasons.
kern_return_t IMPL(VSPSerialPort, HwResetFIFO)
{
    VSPLog(LOG_PREFIX, "HwResetFIFO called -> tx=%d rx=%d\n",
           tx, rx);
    
    VSPAquireLock(ivars);
    // ?? notify caller (IOUserSerial)
    if (rx) {
        ivars->m_hwStatus.dsr = false;
    }
    
    // ?? notify caller (IOUserSerial)
    if (tx) {
        ivars->m_hwStatus.cts = true;
    }
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwSendBreak_Impl()
// Called during client communication life cycle
kern_return_t IMPL(VSPSerialPort, HwSendBreak)
{
    VSPLog(LOG_PREFIX, "HwSendBreak called -> sendBreak=%d\n", sendBreak);
    
    VSPAquireLock(ivars);
    ivars->m_errorState.gotBreak = sendBreak;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwGetModemStatus_Impl()
// Called during client communication life cycle
kern_return_t IMPL(VSPSerialPort, HwGetModemStatus)
{
    VSPLog(LOG_PREFIX, "HwGetModemStatus called [out] CTS=%d DSR=%d RI=%d DCD=%d\n", //
           ivars->m_hwStatus.cts, ivars->m_hwStatus.dsr, //
           ivars->m_hwStatus.ri, ivars->m_hwStatus.dcd);
    
    VSPAquireLock(ivars);
    if (cts != nullptr) {
        (*cts) = ivars->m_hwStatus.cts;
    }
    
    if (dsr != nullptr) {
        (*dsr) = ivars->m_hwStatus.dsr;
    }
    
    if (ri != nullptr) {
        (*ri) = ivars->m_hwStatus.ri;
    }
    
    if (dcd != nullptr) {
        (*dcd) = ivars->m_hwStatus.dcd;
    }
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramUART_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramUART)
{
    VSPLog(LOG_PREFIX, "HwProgramUART called -> baudRate=%d "
           "nDataBits=%d nHalfStopBits=%d parity=%d\n",
           baudRate, nDataBits, nHalfStopBits, parity);
    
    VSPAquireLock(ivars);
    ivars->m_uartParams.baudRate = baudRate;
    ivars->m_uartParams.nDataBits = nDataBits;
    ivars->m_uartParams.nHalfStopBits = nHalfStopBits;
    ivars->m_uartParams.parity = parity;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramBaudRate_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramBaudRate)
{
    VSPLog(LOG_PREFIX, "HwProgramBaudRate called -> baudRate=%d\n", baudRate);
    
    VSPAquireLock(ivars);
    ivars->m_uartParams.baudRate = baudRate;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramMCR_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramMCR)
{
    VSPLog(LOG_PREFIX, "HwProgramMCR called -> DTR=%d RTS=%d\n",
           dtr, rts);
    
    VSPAquireLock(ivars);
    ivars->m_hwMCR.dtr = dtr;
    ivars->m_hwMCR.rts = rts;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramLatencyTimer_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramLatencyTimer)
{
    VSPLog(LOG_PREFIX, "HwProgramLatencyTimer called -> latency=%d\n",
           latency);
    
    VSPAquireLock(ivars);
    ivars->m_hwLatency = latency;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// HwProgramLatencyTimer_Impl()
// Called during serial port setup or other reason
kern_return_t IMPL(VSPSerialPort, HwProgramFlowControl)
{
    VSPLog(LOG_PREFIX, "HwProgramFlowControl called -> arg=%02x xon=%02x xoff=%02x\n",
           arg, xon, xoff);
    
    VSPAquireLock(ivars);
    ivars->m_hwFlowControl.arg = arg;
    ivars->m_hwFlowControl.xon = xon;
    ivars->m_hwFlowControl.xoff = xoff;
    VSPUnlock(ivars);
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Called by VSPDriver instance to link to parent level
//
void VSPSerialPort::setParent(VSPDriver* parent)
{
    VSPLog(LOG_PREFIX, "setParent called.\n");
    
    if (ivars != nullptr && !ivars->m_parent) {
        ivars->m_parent = parent;
    }
}

// --------------------------------------------------------------------
// Remove link to VSPDriver instance
//
void VSPSerialPort::unlinkParent()
{
    VSPLog(LOG_PREFIX, "unlinkParent called.\n");
    
    ivars->m_parent = nullptr;
}

// --------------------------------------------------------------------
// Set the serial port identifier
//
void VSPSerialPort::setPortIdentifier(uint8_t id)
{
    VSPLog(LOG_PREFIX, "setPortIdentifier id=%d.\n", id);
    ivars->m_portId = id;
}

// --------------------------------------------------------------------
// Get the serial port identifier
//
uint8_t VSPSerialPort::getPortIdentifier()
{
    return ivars->m_portId;
}

// --------------------------------------------------------------------
// Set the serial port link identifier
//
void VSPSerialPort::setPortLinkIdentifier(uint8_t id)
{
    VSPLog(LOG_PREFIX, "setPortLinkIdentifier id=%d.\n", id);
    ivars->m_portLinkId = id;
}

// --------------------------------------------------------------------
// Get the serial port link identifier
//
uint8_t VSPSerialPort::getPortLinkIdentifier()
{
    return ivars->m_portLinkId;
}

// --------------------------------------------------------------------
// Called by VSPDriver instance to set TTY base and number based on
// managed instance of this object instance
kern_return_t VSPSerialPort::setupTTYBaseName()
{
    IOReturn ret;
    OSDictionary* properties = nullptr;
    OSString* baseName = nullptr;
    
    VSPLog(LOG_PREFIX, "setupTTYBaseName called.\n");
    
    // setup custom TTY name
    if ((ret = CopyProperties(&properties)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "setupTTYBaseName: Unable to get properties. code=%d\n", ret);
        return ret;
    }
    
    //CreateNameMatchingDictionary(OSString *serviceName, OSDictionary *matching)
    //baseName = OSString::withCString(kVSPTTYBaseName);
    //properties->setObject(kIOTTYBaseNameKey, baseName);
    
    // write back to driver instance
    if ((ret = SetProperties(properties)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "setupTTYBaseName: Unable to set TTY base name. code=%d\n", ret);
        //return ret; // ??? an error - why???
    }
    
    OSSafeReleaseNULL(baseName);
    OSSafeReleaseNULL(properties);
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Called by RxEchoAsyncEvent in case of 'port is linked' state
//
kern_return_t VSPSerialPort::sendToPortLink(IODataQueueDispatchSource* source)
{
    IOReturn ret;
    VSPSerialPort* port = nullptr;
    TVSPPortLinkItem* item = nullptr;
    
    VSPLog(LOG_PREFIX, "sendToPortLink called.\n");

    VSPAquireLock(ivars);

    void* link;
    uint8_t id = ivars->m_portLinkId;
    if ((ret = ivars->m_parent->getPortLinkById(id, &link)) || !link) {
        VSPLog(LOG_PREFIX, "sendToPortLink: Parent getPortLinkById failed. code=%d\n", ret);
        goto finish;
    }
 
    item = reinterpret_cast(link);
    
    VSPLog(LOG_PREFIX, "sendToPortLink: got linkId=%d\n", item->id);
    
    if (item->sourcePort.id != ivars->m_portId) {
        port = item->sourcePort.port;
    }
    else if (item->targetPort.id != ivars->m_portId) {
        port = item->targetPort.port;
    } else {
        VSPLog(LOG_PREFIX, "sendToPortLink: Double port IDs detectd! myLinkId=%d myPortId=%d\n",
               id, ivars->m_portId);
        ret = kIOReturnInvalid;
        goto finish;
    }
    if (!port) {
        VSPLog(LOG_PREFIX, "sendToPortLink: Linked port NULL pointer! myLinkId=%d myPortId=%d\n",
               id, ivars->m_portId);
        ret = kIOReturnInvalid;
        goto finish;
    }
   
    VSPLog(LOG_PREFIX, "sendToPortLink: got portId=%d\n", port->getPortIdentifier());

    VSPUnlock(ivars);
    return port->sendResponse(source);
    
finish:
    VSPUnlock(ivars);
    return ret;
}

// --------------------------------------------------------------------
// Called by other port instance or RxEchoAsyncEvent
//
kern_return_t VSPSerialPort::sendResponse(IODataQueueDispatchSource* source)
{
    IOReturn ret;
    uint64_t address;

    if (!source) {
        VSPLog(LOG_PREFIX, "sendResponse: Invalid argument.\n");
        return kIOReturnBadArgument;
    }
    
    if (!ivars->m_spi || !ivars->m_rxqbmd) {
        VSPLog(LOG_PREFIX, "sendResponse: Device closed.\n");
        return kIOReturnNotOpen;
    }
    
    VSPAquireLock(ivars);

    // Lock RX dispatch queue source
    if ((ret = ivars->m_rxSource->SetEnable(false)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "sendResponse: RX source SetEnable false failed. code=%d\n", ret);
        goto finish;
    }
    
    // Update modem status
    ivars->m_hwStatus.cts = false;
    ivars->m_hwStatus.dsr = false;

    VSPLog(LOG_PREFIX, "sendResponse: [IOSPI-RX 1] rxPI=%d rxCI=%d rxqoffset=%d rxqlogsz=%d\n",
           ivars->m_spi->rxPI, ivars->m_spi->rxCI, ivars->m_spi->rxqoffset, ivars->m_spi->rxqlogsz);
    
    // reset [!! 1 !!]
    // We start always our response from beginning
    // of the memory descriptor buffer
    ivars->m_spi->rxPI = 0;
    ivars->m_spi->rxCI = 0;
    
    // Get address to the RX ring buffer
    address = ivars->m_rxseg.address + ivars->m_spi->rxPI;
    ivars->m_rxstate.buffer = reinterpret_cast(address);
    ivars->m_rxstate.length = 0;
    
    VSPLog(LOG_PREFIX, "sendResponse: dequeue RX source\n");
    
    // Remove queue entry from RX queue source
    ret = ivars->m_rxSource->Dequeue(^(const void *data, size_t dataSize) {
        VSPLog(LOG_PREFIX, "sendResponse: dequeue data=0x%llx size=%ld\n", (uint64_t) data, dataSize);
        // Copy data from RX queue source to RX-MD buffer
        memcpy(ivars->m_rxstate.buffer, data, dataSize);
        // Save transfered data size
        ivars->m_rxstate.length = (uint32_t) dataSize;
    });
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "sendResponse: RX dequeue failed. code=%d\n", ret);
        switch (ret) {
            case kIOReturnUnderrun:
                VSPLog(LOG_PREFIX, "sendResponse: ^^-> underrun\n");
                break;
            case kIOReturnError:
                VSPLog(LOG_PREFIX, "sendResponse: ^^-> corrupt\n");
                break;
        }
        goto finish;
    }
    
    // Notify queue entry has been removed
    ivars->m_rxSource->SendDataServiced();
    
#ifdef DEBUG // !! Debug ....
    VSPLog(LOG_PREFIX, "sendResponse: Dump m_rxqmd buffer=0x%llx size=%u\n",
           (uint64_t) ivars->m_rxstate.buffer, ivars->m_rxstate.length);
    
    for (uint64_t i = 0; i < ivars->m_rxstate.length; i++) {
        VSPLog(LOG_PREFIX, "sendResponse: buffer[%02lld]=0x%02x %c\n", i,
               ivars->m_rxstate.buffer[i], ivars->m_rxstate.buffer[i]);
    }
#endif
    
    // Update RX producer index
    ivars->m_spi->rxPI = ivars->m_rxstate.length;
    
    VSPLog(LOG_PREFIX, "sendResponse: [IOSPI-RX 2] rxPI=%d rxCI=%d rxqoffset=%d rxqlogsz=%d\n",
           ivars->m_spi->rxPI, ivars->m_spi->rxCI, ivars->m_spi->rxqoffset, ivars->m_spi->rxqlogsz);
        
    // Notify OS interrest parties
    this->RxDataAvailable_Impl();

    // Update modem status
    ivars->m_hwStatus.cts = true;
    ivars->m_hwStatus.dsr = true;

    // Unlock RX queue source
    if ((ret = ivars->m_rxSource->SetEnable(true)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "sendResponse: RX source SetEnable true failed. code=%d\n", ret);
    }
    
    VSPLog(LOG_PREFIX, "sendResponse: complete.\n");
    
finish:
    VSPUnlock(ivars);
    return ret;
}

// Notify RX complete to OS interrest parties
// using client defined latency time
//ret = ivars->m_tiSource->WakeAtTime(
//                                    kIOTimerClockMonotonicRaw,
//                                    clock_gettime_nsec_np(CLOCK_MONOTONIC_RAW)
//                                    + (ivars->m_hwLatency * 1000000),
//                                    1000000000);
//if (ret != kIOReturnSuccess) {
//    VSPLog(LOG_PREFIX, "RxEchoAsyncEvent: tiSource WakeAtTime failed. code=%d\n", ret);
//    goto finish;
//}

// ********************************************************************
// VSPDriver - Driver root object
//
// Copyright © 2025 by EoF Software Labs
// Copyright © 2024 Apple Inc. (some copied parts)
// SPDX-License-Identifier: MIT
// ********************************************************************

// -- OS
#include 
#include 

#include 
#include 
#include 
#include 
#include 
#include 

// -- My
#include "VSPDriver.h"
#include "VSPLogger.h"
#include "VSPSerialPort.h"
#include "VSPController.h"
#include "VSPUserClient.h"

#define LOG_PREFIX "VSPDriver"

#define kVSPSerialPortProperties "SerialPortProperties"
#define kVSPContollerProperties  "UserClientProperties"
#define kVSPDefaultPortCount 4
#define kVSPMaxumumPorts 16

// Driver instance state resource
struct VSPDriver_IVars {
    uint8_t               m_portCount = 0;              // number of allocated serial ports
    TVSPSerialPortItem**  m_serialPorts = nullptr;      // list of allocated serial ports
    uint8_t               m_portLinkCount = 0;          // number of serial port links
    TVSPPortLinkItem**    m_portLinks = nullptr;        // list of serial port links
};

// --------------------------------------------------------------------
// Allocate internal resources
//
bool VSPDriver::init(void)
{
    bool result;
    
    VSPLog(LOG_PREFIX, "init called.\n");
    
    if (!(result = super::init())) {
        VSPLog(LOG_PREFIX, "free (super) falsed. result=%d\n", result);
        goto finish;
    }
    
    // Create instance state resource
    ivars = IONewZero(VSPDriver_IVars, 1);
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Unable to allocate driver data.\n");
        result = false;
        goto finish;
    }
    
    VSPLog(LOG_PREFIX, "init finished.\n");
    return true;
    
finish:
    return result;
}

// --------------------------------------------------------------------
// Release internal resources
//
void VSPDriver::free(void)
{
    VSPLog(LOG_PREFIX, "free called.\n");
    
    // Release instance state resource
    IOSafeDeleteNULL(ivars, VSPDriver_IVars, 1);
    super::free();
}

// --------------------------------------------------------------------
// Start_Impl(IOService* provider)
//
kern_return_t IMPL(VSPDriver, Start)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Start: called.\n");
    
    // sane check our driver instance vars
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Start: Private driver instance is NULL\n");
        return kIOReturnInvalid;
    }
    
    // Start service instance (Apple style super call)
    ret = Start(provider, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start(super): failed. code=%d\n", ret);
        return ret;
    }
    
    // Create 4 serial port instances with each IOSerialBSDClient as a child instance
    if ((ret = CreateSerialPort(provider, kVSPDefaultPortCount)) != kIOReturnSuccess) {
        goto finish;
    }
    
    // Register driver instance to IOReg
    if ((ret = RegisterService()) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start: RegisterService failed. code=%d\n", ret);
        goto finish;
    }
    
    VSPLog(LOG_PREFIX, "Start: driver started successfully.\n");
    return kIOReturnSuccess;
    
finish:
    Stop(provider, SUPERDISPATCH);
    return ret;
}

// --------------------------------------------------------------------
// Stop_Impl(IOService* provider)
//
kern_return_t IMPL(VSPDriver, Stop)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Stop called.\n");
        
    // release allocated port links and port items.
    // Do not release VSPSerialPort instance itself!
    if (ivars) {
        // release all link items and the list
        if (ivars->m_portLinks && ivars->m_portLinkCount) {
            for (uint8_t i = 0; i < ivars->m_portLinkCount; i++) {
                IOSafeDeleteNULL(ivars->m_portLinks[i], TVSPPortLinkItem, 1);
            }
        }
        IOSafeDeleteNULL(ivars->m_portLinks, TVSPPortLinkItem*, ivars->m_portLinkCount);

        // release all port items and the list
        if (ivars->m_serialPorts && ivars->m_portCount) {
            for (uint8_t i = 0; i < ivars->m_portCount; i++) {
                ivars->m_serialPorts[i]->port->unlinkParent();
                IOSafeDeleteNULL(ivars->m_serialPorts[i], TVSPSerialPortItem, 1);
            }
        }
        IOSafeDeleteNULL(ivars->m_serialPorts, VSPSerialPort*, ivars->m_portCount);
    }
    
    // service instance (Apple style super call)
    if ((ret= Stop(provider, SUPERDISPATCH)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Stop (suprt) failed. code=%d\n", ret);
    } else {
        VSPLog(LOG_PREFIX, "driver successfully removed.\n");
    }
    
    return ret;
}

// --------------------------------------------------------------------
// NewUserClient_Impl(uint32_t type, IOUserClient ** userClient)
//
kern_return_t IMPL(VSPDriver, NewUserClient)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "NewUserClient called.\n");

    if (!userClient) {
        VSPLog(LOG_PREFIX, "NewUserClient: Invalid argument.\n");
        return kIOReturnBadArgument;
    }
    
    if ((ret = CreateUserClient(GetProvider(), userClient)) != kIOReturnSuccess) {
        return ret;
    }
    
    VSPLog(LOG_PREFIX, "NewUserClient finished.\n");
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Create given number of VSPSerialPort instances
//
kern_return_t VSPDriver::CreateSerialPort(IOService* provider, uint8_t count)
{
    kern_return_t ret;
    IOService* service;
    
    VSPLog(LOG_PREFIX, "CreateSerialPort: create #%d VSPSerialPort from Info.plist.\n", count);
    
    // reset first
    ivars->m_portCount = 0;

    // Allocate serial port list. Holds each allocated
    // instance of the VSPSerialPort object
    ivars->m_serialPorts = IONewZero(TVSPSerialPortItem*, count);
    if (!ivars->m_serialPorts) {
        VSPLog(LOG_PREFIX, "CreateSerialPort: Out of memory.\n");
        return kIOReturnNoMemory;
    }
    
    // do it
    for (uint8_t i = 0; i < count && i < kVSPMaxumumPorts; i++) {
        VSPLog(LOG_PREFIX, "CreateSerialPort: Create serial port %d.\n", i);
        
        TVSPSerialPortItem* item = IONewZero(TVSPSerialPortItem, 1);
        if (!item) {
            VSPLog(LOG_PREFIX, "CreateSerialPort: Ouch out of memory.\n");
            IOSafeDeleteNULL(ivars->m_serialPorts, TVSPSerialPortItem*, count);
            return kIOReturnNoMemory;
        }

        // Create sub service object from UserClientProperties in Info.plist
        ret= Create(this, kVSPSerialPortProperties, &service);
        if (ret != kIOReturnSuccess || service == nullptr) {
            VSPLog(LOG_PREFIX, "CreateSerialPort: create [%d] failed. code=%d\n", count, ret);
            IOSafeDeleteNULL(ivars->m_serialPorts, TVSPSerialPortItem*, count);
            IOSafeDeleteNULL(item, TVSPSerialPortItem, 1);
            return ret;
        }
        
        VSPLog(LOG_PREFIX, "CreateSerialPort: check VSPSerialPort type.\n");
        
        // Sane check object type
        item->port = OSDynamicCast(VSPSerialPort, service);
        if (item->port == nullptr) {
            VSPLog(LOG_PREFIX, "CreateSerialPort: Cast to VSPSerialPort failed.\n");
            IOSafeDeleteNULL(ivars->m_serialPorts, TVSPSerialPortItem*, count);
            IOSafeDeleteNULL(item, TVSPSerialPortItem, 1);
            service->release();
            return kIOReturnInvalid;
        }
        
        item->id = i + 1;
        item->flags = 0x00;
        item->port->setParent(this);                // set this as parent
        item->port->setPortIdentifier(item->id);    // set unique identifier
        
        // save instance for controller
        ivars->m_serialPorts[i] = item;
        ivars->m_portCount++;
    }
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Create the 'VSP Controller' user client instances
//
kern_return_t VSPDriver::CreateUserClient(IOService* provider, IOUserClient** userClient)
{
    kern_return_t ret;
    IOService* service;
    
    VSPLog(LOG_PREFIX, "CreateUserClient: create VSP user client from Info.plist.\n");
    
    if (!userClient) {
        VSPLog(LOG_PREFIX, "CreateUserClient: Bad argument 'userClient' detected.\n");
        return kIOReturnBadArgument;
    }
    
    // Create sub service object from UserClientProperties in Info.plist
    ret= Create(this, kVSPContollerProperties, &service);
    if (ret != kIOReturnSuccess || service == nullptr) {
        VSPLog(LOG_PREFIX, "CreateUserClient: create failed. code=%d\n", ret);
        return ret;
    }
    
    VSPLog(LOG_PREFIX, "CreateUserClient: check VSPUserClient type.\n");
    
    // Sane check object type
    VSPUserClient* client;
    client = OSDynamicCast(VSPUserClient, service);
    if (client == nullptr) {
        VSPLog(LOG_PREFIX, "CreateUserClient: Cast to VSPUserClient failed.\n");
        service->release();
        return kIOReturnInvalid;
    }
    
    client->setParent(this);
    (*userClient) = client;
    
    VSPLog(LOG_PREFIX, "CreateUserClient: success.");
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Check serial port id
//
kern_return_t VSPDriver::checkPortId(uint8_t id)
{
    if (id && id < ivars->m_portCount) {
        return kIOReturnSuccess;
    }
    return kIOReturnInvalid;
}

// --------------------------------------------------------------------
// Check serial port link id
//
kern_return_t VSPDriver::checkPortLinkId(uint8_t id)
{
    if (id && id < ivars->m_portLinkCount) {
        return kIOReturnSuccess;
    }
    return kIOReturnInvalid;
}

// --------------------------------------------------------------------
// Return nummer of allocated serial ports
//
kern_return_t VSPDriver::getPortCount(uint8_t* count)
{
    if (!count) {
        return kIOReturnBadArgument;
    }
    
    (*count) = ivars->m_portCount;
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Return all IDs of all allocated serial ports
//
kern_return_t VSPDriver::getPortList(uint8_t* list, uint8_t count)
{
    if (!list || count >= ivars->m_portCount) {
        return kIOReturnBadArgument;
    }
    
    if (ivars->m_portCount == 0 || !ivars->m_serialPorts) {
        return kIOReturnNotFound;
    }
    
    for(uint8_t i = 0; i < count && i < ivars->m_portCount; i++) {
        list[i] = ivars->m_serialPorts[i]->id;
    }
    
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Create a link between two serial ports
//
kern_return_t VSPDriver::createPortLink(uint8_t sourceId, uint8_t targetId, void** link)
{
    if (!link || checkPortId(sourceId) || checkPortId(targetId)) {
        VSPLog(LOG_PREFIX, "createPortLink: Invalid arguments\n");
        return kIOReturnBadArgument;
    }
  
    TVSPSerialPortItem* src = nullptr;
    TVSPSerialPortItem* tgt = nullptr;
    
    // check serial port list
    for (uint8_t i = 0; i < ivars->m_portCount; i++) {
        
        // skip invalid entry
        if (!ivars->m_serialPorts[i] || !ivars->m_serialPorts[i]->port) {
            continue;
        }
        
        const TVSPSerialPortItem* port = ivars->m_serialPorts[i];
        uint8_t linkId;
        
        if (port->id == sourceId) {
            if ((linkId = port->port->getPortLinkIdentifier()) == 0) {
                src = ivars->m_serialPorts[i];
            } else {
                VSPLog(LOG_PREFIX, "createPortLink: Source port %d already assigned to link %d.",
                       port->id, linkId);
                return kIOReturnBadArgument;
            }
        }

        if (port->id == targetId) {
            if ((linkId = port->port->getPortLinkIdentifier()) == 0) {
                tgt = ivars->m_serialPorts[i];
            } else {
                VSPLog(LOG_PREFIX, "createPortLink: Target port %d already assigned to link %d.",
                       port->id, linkId);
                return kIOReturnBadArgument;
            }
        }
    }
    
    if (src == nullptr || tgt == nullptr) {
        VSPLog(LOG_PREFIX, "createPortLink: Can't find sourceId=%d or targetId=%d\n",
               sourceId, targetId);
        return kIOReturnNotFound;
    }

    uint8_t count = ivars->m_portLinkCount;
 
    // double check existing links
    if (count && ivars->m_portLinks) {
        for (uint8_t i = 0; i < count; i++) {
            // skip invalid entry
            if (!ivars->m_portLinks[i]) {
                continue;;
            }
            
            TVSPPortLinkItem* link = ivars->m_portLinks[i];
            
            if (link->sourcePort.id == src->id) {
                VSPLog(LOG_PREFIX, "createPortLink: Source port %d already assigned to link %d\n",
                       src->id, link->id);
                return kIOReturnBadArgument;
            }
            
            if (link->targetPort.id == tgt->id) {
                VSPLog(LOG_PREFIX, "createPortLink: Target port %d already assigned to link %d\n",
                       tgt->id, link->id);
                return kIOReturnBadArgument;
            }
        }
    }

    // create new link item
    TVSPPortLinkItem* item = nullptr;
    if (!(item = IONewZero(TVSPPortLinkItem, 1))) {
        VSPLog(LOG_PREFIX, "createPortLink: Out of memory!\n");
        return kIOReturnNoMemory;
    }
    
    // new list with additional space
    TVSPPortLinkItem** newl = nullptr;
    if (!(newl = IONewZero(TVSPPortLinkItem*, count + 1))) {
        VSPLog(LOG_PREFIX, "createPortLink: Out of memory!\n");
        IOSafeDeleteNULL(item, TVSPPortLinkItem, 1);
        return kIOReturnNoMemory;
    }
    
    /* copy existing links */
    if (count && ivars->m_portLinks) {
        for (uint8_t i = 0; i < count; i++) {
            if (ivars->m_portLinks[i] != nullptr) {
                newl[i] = ivars->m_portLinks[i];
            }
        }
    }

    // old list to remove
    TVSPPortLinkItem** oldl = ivars->m_portLinks;

    // setup new port link item
    item->id = count + 1;
    item->sourcePort.id = src->id;
    item->sourcePort.port = src->port;
    item->sourcePort.flags = 0x01;
    src->port->setPortLinkIdentifier(item->id);
    
    item->targetPort.id = tgt->id;
    item->targetPort.port = tgt->port;
    item->targetPort.flags = 0x01;
    tgt->port->setPortLinkIdentifier(item->id);
   
    // set new link item
    newl[count] = item;
    
    // return new item
    (*link) = item;
    
    // update global members
    ivars->m_portLinks = newl;
    ivars->m_portLinkCount++;

    IOSafeDeleteNULL(oldl, TVSPPortLinkItem*, count);
    return kIOReturnSuccess; // done!
}

// --------------------------------------------------------------------
// Removes prior created serial port link
//
kern_return_t VSPDriver::removePortLink(void *link)
{
    if (!link) {
        VSPLog(LOG_PREFIX, "removePortLink: Invalid argument.");
        return kIOReturnBadArgument;
    }
    
    if (ivars->m_portLinkCount == 0 || !ivars->m_portLinks) {
        VSPLog(LOG_PREFIX, "removePortLink: No serial port links available.");
        return kIOReturnNotFound;
    }
            
    TVSPPortLinkItem* item = reinterpret_cast(link);
    uint8_t count = ivars->m_portLinkCount;
    uint8_t found = 0;
    
    // old port list to remove
    TVSPPortLinkItem** oldl = ivars->m_portLinks;

    // new port link list
    TVSPPortLinkItem** newl;
    if (!(newl= IONewZero(TVSPPortLinkItem*, count - 1))) {
        VSPLog(LOG_PREFIX, "removePortLink: Out of memory.\n");
        return kIOReturnNoMemory;
    }

    /* find given link item and exclude this from new new list */
    for (uint8_t i = 0, j = 0; i < count; i++) {
        if (item->id == ivars->m_portLinks[i]->id) {
            VSPLog(LOG_PREFIX, "removePortLink: Link Id=%d found :)\n", item->id);
            if (item->sourcePort.port) {
                item->sourcePort.port->setPortLinkIdentifier(0);
            }
            if (item->targetPort.port) {
                item->targetPort.port->setPortLinkIdentifier(0);
            }
            found = 1;
        } else {
            newl[j++] = ivars->m_portLinks[i];
        }
    }

    // remove port link
    if (found) {
        ivars->m_portLinks = newl;
        ivars->m_portLinkCount--;
        IOSafeDeleteNULL(item, TVSPPortLinkItem, 1);
        IOSafeDeleteNULL(oldl, TVSPPortLinkItem*, count);
        return kIOReturnSuccess; // done!
    }

    IOSafeDeleteNULL(newl, TVSPPortLinkItem*, count - 1);
    return kIOReturnNotFound;
}

// --------------------------------------------------------------------
// Return number of created serial port links
//
kern_return_t VSPDriver::getPortLinkCount(uint8_t* count)
{
    if (!count) {
        VSPLog(LOG_PREFIX, "getPortLinkCount: Invalid argument.");
        return kIOReturnBadArgument;
    }
    
    (*count) = ivars->m_portLinkCount;
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// Return a serial port link item specified by id
//
kern_return_t VSPDriver::getPortLinkById(uint8_t id, void** result)
{
    if (checkPortLinkId(id) || !result) {
        VSPLog(LOG_PREFIX, "getPortLinkById: Invalid argument.");
        return kIOReturnBadArgument;
    }
    
    if (ivars->m_portLinkCount == 0 || !ivars->m_portLinks) {
        VSPLog(LOG_PREFIX, "removePortLink: No serial port links available.");
        return kIOReturnNotFound;
    }

    for (uint8_t i = 0; i < ivars->m_portLinkCount; i++) {
        if (ivars->m_portLinks[i]->id == id) {
            (*result) = ivars->m_portLinks[i];
            return kIOReturnSuccess;
        }
    }

    return kIOReturnNotFound;
}

// --------------------------------------------------------------------
// Return a serial port link item specified by source and target ID of
// a serial port instance
//
kern_return_t VSPDriver::getPortLinkByPorts(uint8_t sourceId, uint8_t targetId, void** link)
{
    if (checkPortId(sourceId) || checkPortId(targetId) || !link) {
        VSPLog(LOG_PREFIX, "getPortLinkByPorts: Invalid argument.");
        return kIOReturnBadArgument;
    }
    
    uint8_t count = ivars->m_portLinkCount; 
    if (count && ivars->m_portLinks) {
        for (uint8_t i = 0; i < count; i++) {
            // skip invalid entry
            if (!ivars->m_portLinks[i]) {
                continue;;
            }
            TVSPPortLinkItem* item = ivars->m_portLinks[i];
            if (item->sourcePort.id == sourceId && item->targetPort.id == targetId) {
                (*link) = item;
                return kIOReturnSuccess;
            }
        }
    }

    return kIOReturnNotFound;
}

// ********************************************************************
// VSPUserClient.cpp - VSP controller object
//
// Copyright © 2025 by EoF Software Labs
// Copyright © 2024 Apple Inc. (some copied parts)
// SPDX-License-Identifier: MIT
// ********************************************************************

// -- OS
#include 
#include 
#include 
#include 

#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 
#include 

// -- My
#include "VSPUserClient.h"
#include "VSPController.h"
#include "VSPLogger.h"
#include "VSPDriver.h"
using namespace VSPController;

#define LOG_PREFIX "VSPUserClient"

#define VSP_METHOD(x) ((IOUserClientMethodFunction) &VSPUserClient::x)

#define VSP_CHECK_PARAM_RETURN(f, p) \
{ \
    if (p == nullptr) { \
        VSPLog(LOG_PREFIX, "%s: Invalid argument '" f "' detected", __func__); \
        return kIOReturnBadArgument; \
    } \
}

struct VSPUserClient_IVars {
    IOService* m_provider = nullptr;
    VSPDriver* m_parent = nullptr;
    IODispatchQueue* m_eventQueue = nullptr;
    IOTimerDispatchSource* m_eventSource = nullptr;
    OSAction* m_eventAction = nullptr;
    OSAction* m_cbAction = nullptr;
};

// Define all possible commands with its parameters and callback entry points.
const IOUserClientMethodDispatch uc_methods[vspLastCommand] = {
    [vspControlGetStatus] =
    {
        .function = VSP_METHOD(exGetStatus),
        .checkCompletionExists = true,
        .checkScalarInputCount = 0,
        .checkScalarOutputCount = 0,
        .checkStructureInputSize = VSP_UCD_SIZE,
        .checkStructureOutputSize = VSP_UCD_SIZE,
    },
    [vspControlGetPortList] =
    {
        .function = VSP_METHOD(exGetPortList),
        .checkCompletionExists = true,
        .checkScalarInputCount = 0,
        .checkScalarOutputCount = 0,
        .checkStructureInputSize = VSP_UCD_SIZE,
        .checkStructureOutputSize = VSP_UCD_SIZE,
    },
    [vspControlLinkPorts] =
    {
        .function = VSP_METHOD(exLinkPorts),
        .checkCompletionExists = true,
        .checkScalarInputCount = 0,
        .checkScalarOutputCount = 0,
        .checkStructureInputSize = VSP_UCD_SIZE,
        .checkStructureOutputSize = VSP_UCD_SIZE,
    },
    [vspControlUnlinkPorts] =
    {
        .function = VSP_METHOD(exUnlinkPorts),
        .checkCompletionExists = true,
        .checkScalarInputCount = 0,
        .checkScalarOutputCount = 0,
        .checkStructureInputSize = VSP_UCD_SIZE,
        .checkStructureOutputSize = VSP_UCD_SIZE,
    },
    [vspControlEnableChecks] =
    {
        .function = VSP_METHOD(exEnableChecks),
        .checkCompletionExists = true,
        .checkScalarInputCount = 0,
        .checkScalarOutputCount = 0,
        .checkStructureInputSize = VSP_UCD_SIZE,
        .checkStructureOutputSize = VSP_UCD_SIZE,
    },
    [vspControlEnableTrace] =
    {
        .function = VSP_METHOD(exEnableTrace),
        .checkCompletionExists = true,
        .checkScalarInputCount = 0,
        .checkScalarOutputCount = 0,
        .checkStructureInputSize = VSP_UCD_SIZE,
        .checkStructureOutputSize = VSP_UCD_SIZE,
    },
};

static inline void dump_ctrl_data(const TVSPControllerData* request)
{
    VSPLog(LOG_PREFIX, "Data ------------------------------------------\n");
    VSPLog(LOG_PREFIX, "Data.context..........: %d\n", request->context);
    VSPLog(LOG_PREFIX, "Data.command..........: %d\n", request->command);
    VSPLog(LOG_PREFIX, "Data.status.code......: %d\n", request->status.code);
    VSPLog(LOG_PREFIX, "Data.status.flags.....: 0x%llx\n", request->status.flags);
    VSPLog(LOG_PREFIX, "Data.parameter.flags..: 0x%llx\n", request->parameter.flags);
    VSPLog(LOG_PREFIX, "Data.p.portlink.source: %d\n", request->parameter.portLink.sourceId);
    VSPLog(LOG_PREFIX, "Data.p.portlink.target: %d\n", request->parameter.portLink.targetId);
}

static inline const TVSPControllerData* toVspData(const OSData* p)
{
    return reinterpret_cast(p->getBytesNoCopy());
}

void set_ctlr_status(TVSPControllerData* data, uint32_t code, uint64_t flags)
{
    data->context = (code == kIOReturnSuccess ? vspContextResult : vspContextError);
    data->status.code = code;
    data->status.flags = flags;
}

// --------------------------------------------------------------------
// Allocate internal resources
//
bool VSPUserClient::init()
{
    bool result;
    
    VSPLog(LOG_PREFIX, "init called.\n");
    
    if (!(result = super::init())) {
        VSPLog(LOG_PREFIX, "free (super) falsed. result=%d\n", result);
        goto finish;
    }
    
    // Create instance state resource
    ivars = IONewZero(VSPUserClient_IVars, 1);
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Unable to allocate driver data.\n");
        result = false;
        goto finish;
    }
    
    VSPLog(LOG_PREFIX, "init finished.\n");
    return true;
    
finish:
    return result;
}

// --------------------------------------------------------------------
// Release internal resources
//
void VSPUserClient::free()
{
    VSPLog(LOG_PREFIX, "free called.\n");
    
    // Release instance state resource
    IOSafeDeleteNULL(ivars, VSPUserClient_IVars, 1);
    super::free();
}

// --------------------------------------------------------------------
// Start_Impl(IOService* provider)
//
kern_return_t IMPL(VSPUserClient, Start)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Start: called.\n");
    
    // sane check our driver instance vars
    if (!ivars) {
        VSPLog(LOG_PREFIX, "Start: Private driver instance is NULL\n");
        return kIOReturnInvalid;
    }
    
    // Start service instance (Apple style super call)
    ret = Start(provider, SUPERDISPATCH);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Start(super): failed. code=%d\n", ret);
        return ret;
    }
    
    ret = IODispatchQueue::Create("NullDriverUserClientDispatchQueue", 0, 0, &ivars->m_eventQueue);
    if (ret != kIOReturnSuccess || !ivars->m_eventQueue)
    {
        VSPLog(LOG_PREFIX, "Start() - Failed to create dispatch queue with error: 0x%08x.", ret);
        if (ret == kIOReturnSuccess) {
            ret = kIOReturnInvalid;
        }
        return ret;
    }
    
    ret = IOTimerDispatchSource::Create(ivars->m_eventQueue, &ivars->m_eventSource);
    if (ret != kIOReturnSuccess || !ivars->m_eventSource)
    {
        VSPLog(LOG_PREFIX, "Start() - Failed to create dispatch source with error: 0x%08x.", ret);
        if (ret == kIOReturnSuccess) {
            ret = kIOReturnInvalid;
        }
        return ret;
    }
    
    ret = CreateActionAsyncCallback(sizeof(TVSPControllerData), &ivars->m_eventAction);
    if (ret != kIOReturnSuccess || !ivars->m_eventAction)
    {
        VSPLog(LOG_PREFIX, "Start() - Failed to create action for simulated async event with error: 0x%08x.", ret);
        if (ret == kIOReturnSuccess) {
            ret = kIOReturnInvalid;
        }
        return ret;
    }
    
    ret = ivars->m_eventSource->SetHandler(ivars->m_eventAction);
    if (ret != kIOReturnSuccess)
    {
        VSPLog(LOG_PREFIX, "Start() - Failed to assign simulated action to handler with error: 0x%08x.", ret);
        return ret;
    }
    
    ret = RegisterService();
    if (ret != kIOReturnSuccess)
    {
        VSPLog(LOG_PREFIX, "Start() - Failed to register service with error: 0x%08x.", ret);
        return ret;
    }
    
    VSPLog(LOG_PREFIX, "User client successfully started.\n");
    return ret;
}

// --------------------------------------------------------------------
// Stop_Impl(IOService* provider)
//
kern_return_t IMPL(VSPUserClient, Stop)
{
    kern_return_t ret;
    
    VSPLog(LOG_PREFIX, "Stop called.\n");
    
    OSSafeReleaseNULL(ivars->m_eventAction);
    OSSafeReleaseNULL(ivars->m_eventSource);
    OSSafeReleaseNULL(ivars->m_eventQueue);
    OSSafeReleaseNULL(ivars->m_cbAction);
    
    // service instance (Apple style super call)
    if ((ret= Stop(provider, SUPERDISPATCH)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "Stop (suprt) failed. code=%d\n", ret);
    } else {
        VSPLog(LOG_PREFIX, "User client successfully removed.\n");
    }
    
    return ret;
}

// --------------------------------------------------------------------
// AsyncCallback_Impl(OSAction* action, uint64_t time)
//
void IMPL(VSPUserClient, AsyncCallback)
{
    VSPLog(LOG_PREFIX, "AsyncCallback called.\n");
    
    if (!action) {
        VSPLog(LOG_PREFIX, "AsyncCallback: Event action NULL pointer!");
        return;
    }
    if (!ivars->m_cbAction) {
        VSPLog(LOG_PREFIX, "AsyncCallback: Client callback action NULL pointer!");
        return;
    }

    // Get back our data previously stored in OSAction.
    TVSPControllerData* eventData = (TVSPControllerData*) action->GetReference();
    
    // Get function response data
    TVSPControllerData response = {};
    memcpy(&response, eventData, VSP_UCD_SIZE);
   
    // Debug !!
    dump_ctrl_data(&response);
    
    // Create async message array
    uint32_t  count   = 8 + response.ports.count;
    uint64_t* message = IONewZero(uint64_t, count);
    
    // Setup message header
    message[0] = response.context;
    message[1] = response.command;
    message[2] = response.parameter.flags;
    message[3] = response.parameter.portLink.sourceId;
    message[4] = response.parameter.portLink.targetId;
    message[5] = response.status.code;
    message[6] = response.status.flags;
    message[7] = response.ports.count;
    
    // Append port list
    for (int i = 8, j = 0; i < count && j < response.ports.count; i++, j++) {
        message[i] = response.ports.list[j];
    }
    
    // dispatch message back to user client
    AsyncCompletion(ivars->m_cbAction, kIOReturnSuccess, message, count);
    
    IOSafeDeleteNULL(message, uint64_t, count);
    return;
}

// --------------------------------------------------------------------
// ExternalMethod(...)
//
kern_return_t VSPUserClient::ExternalMethod(uint64_t selector,
                                            IOUserClientMethodArguments* arguments,
                                            const IOUserClientMethodDispatch* dispatch,
                                            OSObject* target,
                                            void* reference)
{
    kern_return_t ret = kIOReturnSuccess;
    
    VSPLog(LOG_PREFIX, "ExternalMethod called.\n");
    
    if (selector < 1 || selector >= vspLastCommand) {
        VSPLog(LOG_PREFIX, "Invalid method selector detected, skip.");
        return kIOReturnBadArgument;
    }
    
    // Set method dispatch descriptor
    dispatch = &uc_methods[selector];
    target   = (target == nullptr ? this : target);
    reference= (reference == nullptr ? ivars : reference);

    // This will call the functions as defined in the IOUserClientMethodDispatch.
    ret = super::ExternalMethod(selector, arguments, dispatch, target, reference);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "ExternalMethod dispatch failed. code=%d", ret);
        return kIOReturnBadArgument;
    }
    
    return ret;
}

// --------------------------------------------------------------------
// Called by VSPDriver root object
//
void VSPUserClient::setParent(VSPDriver* parent)
{
    if (ivars && !ivars->m_parent) {
        ivars->m_parent = parent;
    }
}

// --------------------------------------------------------------------
// Called by scheduleEvent() and dispatching action as async event
kern_return_t VSPUserClient::scheduleEvent()
{
    VSPLog(LOG_PREFIX, "scheduleEvent called.\n");
    uint64_t       currentTime = clock_gettime_nsec_np(CLOCK_MONOTONIC_RAW);
    currentTime               += 100000000;
    const uint64_t leeway      = 1000000000;
    return ivars->m_eventSource->WakeAtTime(kIOTimerClockMonotonicRaw, currentTime, leeway);
}

// --------------------------------------------------------------------
// Prepares async response
//
kern_return_t VSPUserClient::prepareResponse(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* response = reinterpret_cast(reference);
    
    VSPLog(LOG_PREFIX, "prepareResponse called.\n");

    if (!response) {
        VSPLog(LOG_PREFIX, "prepareResponse Invalid argument 'reference' detected.\n");
        return kIOReturnBadArgument;
    }
    
    if (!arguments || !arguments->completion) {
        VSPLog(LOG_PREFIX, "prepareResponse Invalid argument 'arguments' detected.\n");
        return kIOReturnBadArgument;
    }

    // Save the completion for later. If not saved, then it
    // might be freed before the asychronous return.
    ivars->m_cbAction = arguments->completion;
    ivars->m_cbAction->retain();
        
    // Retain action memory for later work.
    void* evData = ivars->m_eventAction->GetReference();
    memcpy(evData, response, VSP_UCD_SIZE);

    // directly response
    arguments->structureOutput = OSData::withBytes(response, VSP_UCD_SIZE);

    VSPLog(LOG_PREFIX, "prepareResponse finish.\n");
    return kIOReturnSuccess;
}

// --------------------------------------------------------------------
// MARK: Static External Handlers
// --------------------------------------------------------------------

// --------------------------------------------------------------------
// Return status of VSPDriver instance
//
kern_return_t VSPUserClient::exGetStatus(OSObject* target, void* reference, IOUserClientMethodArguments* arguments)
{
    VSPLog(LOG_PREFIX, "exGetStatus called.\n");

    VSP_CHECK_PARAM_RETURN("target", target);
    VSP_CHECK_PARAM_RETURN("arguments", arguments);
    VSP_CHECK_PARAM_RETURN("completion", arguments->completion);

    VSPUserClient* self = (VSPUserClient*) target;
    return self->getStatus(reference, arguments);
}

kern_return_t VSPUserClient::getStatus(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* request = toVspData(arguments->structureInput);
    TVSPControllerData response = {};
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "getStatus called.\n");
    dump_ctrl_data(request);
    
    memcpy(&response, request, VSP_UCD_SIZE);
    
    set_ctlr_status(&response, kIOReturnSuccess, 0xff00be01);

    if ((ret = prepareResponse(&response, arguments)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "getStatus preprare response failed. code=%d\n", ret);
        return ret;
    }
     
    VSPLog(LOG_PREFIX, "getStatus finish.\n");

    return scheduleEvent();
}

// --------------------------------------------------------------------
// Return active port list
//
kern_return_t VSPUserClient::exGetPortList(OSObject* target, void* reference, IOUserClientMethodArguments* arguments)
{
    VSPLog(LOG_PREFIX, "exGetPortList called.\n");
    
    VSP_CHECK_PARAM_RETURN("target", target);
    VSP_CHECK_PARAM_RETURN("arguments", arguments);
    VSP_CHECK_PARAM_RETURN("completion", arguments->completion);

    VSPUserClient* self = (VSPUserClient*) target;
    return self->getPortList(reference, arguments);
}

kern_return_t VSPUserClient::getPortList(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* request = toVspData(arguments->structureInput);
    TVSPControllerData response = {};
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "getPortList called.\n");
    dump_ctrl_data(request);

    memcpy(&response, request, VSP_UCD_SIZE);

    set_ctlr_status(&response, kIOReturnSuccess, 0xff00be01);

    uint8_t* list = nullptr;
    uint8_t count = 0;
    
    if ((ret = ivars->m_parent->getPortCount(&count)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "getPortList: parent getPortCount failed. code=%d\n", ret);
        set_ctlr_status(&response, ret, 0xfa000001);
    }

    if (count > 0) {
        if (!(list = IONewZero(uint8_t, count))) {
            VSPLog(LOG_PREFIX, "getPortList: Out of memory.\n");
            set_ctlr_status(&response, ret, 0xfa0000ff);
        }
        if ((ret = ivars->m_parent->getPortList(list, count)) != kIOReturnSuccess) {
            VSPLog(LOG_PREFIX, "getPortList: parent getPortCount failed. code=%d\n", ret);
            set_ctlr_status(&response, ret, 0xfa000002);
        }
        else {
            for (uint8_t i = 0; i < count; i++) {
                response.ports.list[i] = list[i];
            }
            response.ports.count = count;
        }
        IOSafeDeleteNULL(list, uint8_t, count);
    }

    if ((ret = prepareResponse(&response, arguments)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "getStatus preprare response failed. code=%d\n", ret);
        return ret;
    }

    VSPLog(LOG_PREFIX, "getPortList finish.\n");

    return scheduleEvent();
}

// --------------------------------------------------------------------
// Link two serial ports together
//
kern_return_t VSPUserClient::exLinkPorts(OSObject* target, void* reference, IOUserClientMethodArguments* arguments)
{
    VSPLog(LOG_PREFIX, "exLinkPorts called.\n");
    
    VSP_CHECK_PARAM_RETURN("target", target);
    VSP_CHECK_PARAM_RETURN("arguments", arguments);
    VSP_CHECK_PARAM_RETURN("completion", arguments->completion);

    VSPUserClient* self = (VSPUserClient*) target;
    return self->linkPorts(reference, arguments);
}

kern_return_t VSPUserClient::linkPorts(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* request = toVspData(arguments->structureInput);
    TVSPControllerData response = {};
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "linkPorts called.\n");
    dump_ctrl_data(request);

    memcpy(&response, request, VSP_UCD_SIZE);

    set_ctlr_status(&response, kIOReturnSuccess, 0xff00be01);

    void* link = nullptr;
    uint8_t sid = request->parameter.portLink.sourceId;
    uint8_t tid = request->parameter.portLink.targetId;
    
    ret = ivars->m_parent->createPortLink(sid, tid, &link);
    if (ret != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "linkPorts: parent createPortLink failed. code=%d\n", ret);
        set_ctlr_status(&response, ret, 0xfb000001);
    }
    else if (link) {
        TVSPPortLinkItem* pli = reinterpret_cast(link);
        VSPLog(LOG_PREFIX, "linkPorts: got link ID: %d\n", pli->id);
    }
    
    if ((ret = prepareResponse(&response, arguments)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "linkPorts: preprare response failed. code=%d\n", ret);
        return ret;
    }

    VSPLog(LOG_PREFIX, "linkPorts finish.\n");

    return scheduleEvent();
}

// --------------------------------------------------------------------
// Unlink prior linked ports
//
kern_return_t VSPUserClient::exUnlinkPorts(OSObject* target, void* reference, IOUserClientMethodArguments* arguments)
{
    VSPLog(LOG_PREFIX, "exUnlinkPorts called.\n");

    VSP_CHECK_PARAM_RETURN("target", target);
    VSP_CHECK_PARAM_RETURN("arguments", arguments);
    VSP_CHECK_PARAM_RETURN("completion", arguments->completion);

    VSPUserClient* self = (VSPUserClient*) target;
    return self->unlinkPorts(reference, arguments);
}

kern_return_t VSPUserClient::unlinkPorts(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* request = toVspData(arguments->structureInput);
    TVSPControllerData response = {};
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "unlinkPorts called.\n");
    dump_ctrl_data(request);

    memcpy(&response, request, VSP_UCD_SIZE);

    set_ctlr_status(&response, kIOReturnSuccess, 0xff00be01);

    void* link = nullptr;
    uint8_t sid = request->parameter.portLink.sourceId;
    uint8_t tid = request->parameter.portLink.targetId;
    
    ret = ivars->m_parent->getPortLinkByPorts(sid, tid, &link);
    if (ret != kIOReturnSuccess) {
        set_ctlr_status(&response, ret, 0xfb000001);
    }
    else {
        TVSPPortLinkItem* item = reinterpret_cast(link);
        VSPLog(LOG_PREFIX, "unlinkPorts: remove src=%d tgt=%d in %d\n", sid, tid, item->id);
      
        ret = ivars->m_parent->removePortLink(item);
        if (ret != kIOReturnSuccess) {
            VSPLog(LOG_PREFIX, "unlinkPorts: parent removePortLink failed. code=%d\n", ret);
            set_ctlr_status(&response, ret, 0xfb000002);
        }
    }
    
    if ((ret = prepareResponse(&response, arguments)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "unlinkPorts: preprare response failed. code=%d\n", ret);
        return ret;
    }

    VSPLog(LOG_PREFIX, "unlinkPorts finish.\n");

    return scheduleEvent();
}

// --------------------------------------------------------------------
// Enable serial port parameter check on linkPorts()
//
kern_return_t VSPUserClient::exEnableChecks(OSObject* target, void* reference, IOUserClientMethodArguments* arguments)
{
    VSPLog(LOG_PREFIX, "exEnableChecks called.\n");
    
    VSP_CHECK_PARAM_RETURN("target", target);
    VSP_CHECK_PARAM_RETURN("arguments", arguments);
    VSP_CHECK_PARAM_RETURN("completion", arguments->completion);

    VSPUserClient* self = (VSPUserClient*) target;
    return self->enableChecks(reference, arguments);
}

kern_return_t VSPUserClient::enableChecks(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* request = toVspData(arguments->structureInput);
    TVSPControllerData response = {};
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "enableChecks called.\n");
    dump_ctrl_data(request);
    
    memcpy(&response, request, VSP_UCD_SIZE);

    set_ctlr_status(&response, kIOReturnSuccess, 0xff00be01);

    if ((ret = prepareResponse(&response, arguments)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enableChecks preprare response failed. code=%d\n", ret);
        return ret;
    }

    VSPLog(LOG_PREFIX, "enableChecks finish.\n");

    return scheduleEvent();
}

// --------------------------------------------------------------------
// Enable serial port protocol trace
//
kern_return_t VSPUserClient::exEnableTrace(OSObject* target, void* reference, IOUserClientMethodArguments* arguments)
{
    VSPLog(LOG_PREFIX, "exEnableTrace called.\n");
    
    VSP_CHECK_PARAM_RETURN("target", target);
    VSP_CHECK_PARAM_RETURN("arguments", arguments);
    VSP_CHECK_PARAM_RETURN("completion", arguments->completion);

    VSPUserClient* self = (VSPUserClient*) target;
    return self->enableTrace(reference, arguments);
}

kern_return_t VSPUserClient::enableTrace(void* reference, IOUserClientMethodArguments* arguments)
{
    const TVSPControllerData* request = toVspData(arguments->structureInput);
    TVSPControllerData response = {};
    kern_return_t ret;

    VSPLog(LOG_PREFIX, "enableTrace called.\n");
    dump_ctrl_data(request);

    memcpy(&response, request, VSP_UCD_SIZE);

    set_ctlr_status(&response, kIOReturnSuccess, 0xff00be01);

    if ((ret = prepareResponse(&response, arguments)) != kIOReturnSuccess) {
        VSPLog(LOG_PREFIX, "enableTrace preprare response failed. code=%d\n", ret);
        return ret;
    }

    VSPLog(LOG_PREFIX, "enableTrace finish.\n");

    return scheduleEvent();
}
DriverKit IOUserSerial Driver
 
 
Q