VirtualBox

Opened 5 years ago

Last modified 2 years ago

#18668 new defect

Problem with sharing serial port after upgrade from 5.2.28 to 6.0.X

Reported by: stagadet Owned by:
Component: uart Version: VirtualBox 6.0.8
Keywords: Serial Cc:
Guest type: other Host type: Windows

Description

When I try to use a shared COM port (host device) on a guest running DOS 6.22 (using a legacy software for PLCs), on VirtualBox 6.0.8 (and also 6.0.6) I get errors like: Serial#0: Failed to change parameters to 2400,NONE,5,1 -> VERR_INVALID_PARAMETER and the software cannot communicate.

Everything works fine if I use VirtualBox 5.2.28 instead, with the same virtual machine.

The full log is attached.

Attachments (7)

s5-2019-05-15-08-19-19.log (101.0 KB ) - added by stagadet 5 years ago.
Full log showing the errors
s5-2019-06-17-08-46-46.log (55.5 KB ) - added by stagadet 5 years ago.
Log of version 5.2.28 not showing serial related errors
VBox - v5.2.26.log (82.9 KB ) - added by FelixG 4 years ago.
All ok with v5.2.26
Vbox - v6.1.0.log (89.2 KB ) - added by FelixG 4 years ago.
Nok with v6.1.0
Captures.zip (52.0 KB ) - added by FelixG 4 years ago.
log v6.1.3 - test 1.txt (23.6 KB ) - added by FelixG 4 years ago.
Nok log with testbuild 6.1.3 - test 1
log v6.1.3 - test 2.txt (22.8 KB ) - added by FelixG 4 years ago.
Nok log with testbuild 6.1.3 - test 2

Download all attachments as: .zip

Change History (22)

by stagadet, 5 years ago

Attachment: s5-2019-05-15-08-19-19.log added

Full log showing the errors

comment:1 by aeichner, 5 years ago

What is the supposed serial port setting your software is communicating with the device (baudrate, parity, etc.) The VBox.log contains failed attempts but ones which succeed are not logged so it might be possible that the errors are not relevant to the problem but there is something else going wrong. Can you post a VBox.log from a run with 5.2.28 please?

comment:2 by Socratis, 5 years ago

Related discussion in the forums: https://forums.virtualbox.org/viewtopic.php?f=6&t=93132

Not much of a discussion, simply a Cc: I guess... ;)

comment:3 by stagadet, 5 years ago

Unfortunately I don't know the settings the software I'm using needs to communicate, but using VirtualBox 5.2.28 no VERR_INVALID_PARAMETER error was issued.

I cannot post a VBox.log right now (no access to the hardware), but I will in the next few days.

For now, thank you for your interest.

by stagadet, 5 years ago

Attachment: s5-2019-06-17-08-46-46.log added

Log of version 5.2.28 not showing serial related errors

comment:4 by stagadet, 5 years ago

I attached the log of VBox version 5.2.28 that is communicating fine and not showing any error.

If needed I can provide the VM (without the PLC you cannot communicate, but the errors are shown anyway). All the software is at least 20 years old, so I hope I'm not violating copyright laws.

comment:5 by vitaliy, 4 years ago

I have a similar problem when using hardware flow control on a guest machine (I use write to raw file)

comment:6 by Solartrand, 4 years ago

I have a similar issue with 6.0.12, I have an instrument connected via serial port (windows 10 host, xp sp1 64 client) to the virtual pc that communicates well on version 5.2.6, but with the new version I get erratic communication that works partly, up to a point where the communication fails and freezes over the software controlling the hardware (No error from the VM). I could not find something in the log related to this (that I can interpret anyways). Restarting the VM usually will make the communication works for a brief (random) amount of time before it freeze again.

Downgrading back to 5.2.6 fixed my issue. Since this is for a working instrument I can't debug as much as I want, but I wanted to share that there is still an issue.

comment:7 by FelixG, 4 years ago

I have the same problem. Windows 10 host and Ecomstation guest. The software is old and does not show error, it tries the communication but it does not get it, apparently the serial port is not configured correctly. With VirtualBox version 6.0 and 6.1, the VBox.log shows:

Serial # 0: emulating 16550A (IOBase: 03f8 IRQ: 4)

Serial # 0: Failed to change parameters to 9600, NONE, 5.1 -> VERR_INVALID_PARAMETER

Serial # 0: Failed to change parameters to 9600, NONE, 5.1 -> VERR_INVALID_PARAMETER

With version 5.2.26 everything works correctly, and only shows:

Serial # 0: emulating 16550A

by FelixG, 4 years ago

Attachment: VBox - v5.2.26.log added

All ok with v5.2.26

by FelixG, 4 years ago

Attachment: Vbox - v6.1.0.log added

Nok with v6.1.0

comment:8 by FelixG, 4 years ago

My serial port is an FTDI model USB adapter.

I have monitored the serial communication and cannot find the problem. But I make the following observations:

With v5.2.34:

300, 9600, and 19200 Baud Rates appear.

IOCTL_SERIAL_SET_CHARS: Set special characters

· EOF = 0

· Error = 0

· Break = 0

· Event = 0

· XON = 0

· XOFF = 0

IOCTL_SERIAL_SET_HANDFLOW: Set handshake information

· Control lines = 0

· Flow control = SERIAL_XOFF_CONTINUE (0x80000000)

· Xon Limit = 5

· Xoff Limit = 5

With v6.1:

300, 429, 900, 9600 and 19200 Baud Rates appear. 429 is a very strange value!

IOCTL_SERIAL_SET_CHARS: Set special characters

· EOF = 0

· Error = 0

· Break = 0

· Event = 0

· XON = 0x11

· XOFF = 0x13

IOCTL_SERIAL_SET_HANDFLOW: Set handshake information

· Control lines = 0

· Flow control = SERIAL_RTS_CONTROL (0x40)

· Xon Limit = 2048

· Xoff Limit = 512

Perhaps in v6.1 there is a problem with the Xon / Xoff configuration.

by FelixG, 4 years ago

Attachment: Captures.zip added

comment:9 by aeichner, 4 years ago

As I wasn't able to reproduce the issue so far we need some special logs from the serial port emulation. I prepared a testbuild which can be downloaded from here, look for the latest development testbuild (6.1.2+ state). In order to activate the tracing the VM needs some special config which can be added with

VBoxManage setextradata <VM name> "VBoxInternal/PDM/DriverTransformations/SerialTrace/AboveDriver"                         "Host Serial"
VBoxManage setextradata <VM name> "VBoxInternal/PDM/DriverTransformations/SerialTrace/AttachedDriver/Config/TraceFilePath" "<trace/log/file/path>"
VBoxManage setextradata <VM name> "VBoxInternal/PDM/DriverTransformations/SerialTrace/AttachedDriver/Driver"               "IfTrace"

<trace/log/file/path> needs to be substituted with a file path the user as write access to. <VM name> needs to be substituted with the VM name being traced. The current setup doesn't work if you have multiple serial ports configured which are using a host serial port device, so be sure to either disable all but one or leave them disconnected. Depending on the size the resulting logs can either be attached to this defect (they don't contain any data being transfered but only metadata about timings and parameters of certain function calls) or can be sent directly to Alexander (dot) Eichner (at) oracle (dot) com.

For the last reported issue (xon/xoff differences between 5.2 and 6.0/6.1) there already might be fix in the testbuild, so please try if this is still an issue and collect a log from the VM and your monitoring setup if possible for comparison, thanks!

by FelixG, 4 years ago

Attachment: log v6.1.3 - test 1.txt added

Nok log with testbuild 6.1.3 - test 1

by FelixG, 4 years ago

Attachment: log v6.1.3 - test 2.txt added

Nok log with testbuild 6.1.3 - test 2

comment:10 by FelixG, 4 years ago

The log only works with v6.1.3.

With testbuild v5.2.35 an error message appears: The configured driver wasn't found. Either the necessary driver modules wasn't loaded, the name was misspelled, or it was a misconfiguration. (VERR_PDM_DRIVER_NOT_FOUND).

comment:11 by aeichner, 4 years ago

Thanks for the logs! Yes the tracing code is in 6.1 only, do you still see the differences in your monitoring setup between 5.2 and 6.1 regarding Xon/Xoff handling?

comment:12 by FelixG, 4 years ago

Sorry for waiting.

There is a moment at the beginning of the communication in which after a reading there is an immediate writing in v5.2 (Events 426-428 in OK_Capture.txt).

However, in v6.1 (Events 4844-4855 in NOK_Capture.txt) there is an exact 7-second wait and the program restarts the communication. It seems as if I don't see the end of the stream.

Comparing the captures of both versions I observe that in v6.1 many new events appear, while they do not exist in v5.2:

IOCTL: IOCTL_SERIAL_GET_COMMSTATUS (0x1b006c)

IOCTL_SERIAL_GET_COMMSTATUS: Retrieve COM status

· Errors = 0

· Hold reasons = 0

· In queue = 0

· Out queue = 0

· EOF received = false

· Wait for immediate = false

IOCTL_SERIAL_SET_WAIT_MASK: Set wait mask

· Wait Mask = SERIAL_EV_RXCHAR | SERIAL_EV_TXEMPTY | SERIAL_EV_CTS | SERIAL_EV_DSR | SERIAL_EV_RLSD | SERIAL_EV_BREAK | SERIAL_EV_ERR | SERIAL_EV_RING (0x1fd)

IOCTL_SERIAL_WAIT_ON_MASK: Wait for event

· Wait Mask = 0

IOCTL: IOCTL_SERIAL_SET_WAIT_MASK (0x1b0044)

.

As a last note, I observe in v5.2 (OK) and in v6.1.2-135663 (NOK):

IOCTL_SERIAL_SET_CHARS: Set special characters

· EOF = 0

· Error = 0

· Break = 0

· Event = 0

· XON = 0

· XOFF = 0

IOCTL: IOCTL_SERIAL_SET_CHARS (0x1b005c)

While in v6.1.3-135750 (NOK):

IOCTL_SERIAL_SET_CHARS: Set special characters

· EOF = 0

· Error = 0

· Break = 0

· Event = 0

· XON = 0x11

· XOFF = 0x13

IOCTL: IOCTL_SERIAL_SET_CHARS (0x1b005c)

.

I hope this data can help you find the problem.

comment:13 by FelixG, 3 years ago

I have found the problem.

The driver I use, reads the received bytes one by one, and needs the interrupt to hold as long as bytes remain in the buffer.

In \VirtualBox-5.2.34\src\VBox\Devices\Serial\DevSerial.cpp, the routine "serial_update_irq" always updates the interrupt (PDMDevHlpISASetIrqNoWait / PDMDevHlpPCISetIrqNoWait).

When the RBR register is read, the "serial_ioport_read" routine calls "serial_update_irq", and therefore the interrupt is updated even if only one byte is read.

In \VirtualBox-6.1.x\src\VBox\Devices\Serial\UartCore.cpp, the routine "uartIrqUpdate" updates only the interrupt (pfnUartIrqReq) when it detects a change in the LSR register (line status) and IER register (interrupt status).

When the RBR register is read, the "uartR3ByteFetch" routine calls "uartIrqUpdate", but since there are no changes to LSR.DR, the interrupt is NOT updated when only one byte is read.

To fix it, I think the following change to the "uartIrqUpdate" routine is sufficient:

if (uRegIirNew != (pThis->uRegIir & UART_REG_IIR_CHANGED_MASK))

LogFlow((" Interrupt source changed from %#x -> %#x (IRQ %d -> %d)\n",

pThis->uRegIir, uRegIirNew, pThis->uRegIir == UART_REG_IIR_IP_NO_INT ? 0 : 1, uRegIirNew == UART_REG_IIR_IP_NO_INT ? 0 : 1));

else

LogFlow((" No change in interrupt source\n"));

if (uRegIirNew == UART_REG_IIR_IP_NO_INT)

pThisCC->pfnUartIrqReq(pDevIns, pThis, pThis->iLUN, 0);

else

pThisCC->pfnUartIrqReq(pDevIns, pThis, pThis->iLUN, 1);

comment:14 by aeichner, 3 years ago

Thanks a lot for the diagnosis! I incorporated the patch into 6.1 and it will be available in the next maintenance release.

comment:15 by FelixG, 2 years ago

I have encountered the same problem in a DOS software, and have been investigating.

In VirtualBox v5.2 when the RBR register is read, the routine "serial_ioport_read" 'case 0' (DevSerial.cpp) always resets the LSR_DR bit (and the LSR_BI,"break").

                ret = pThis->rbr;
                pThis->lsr &= ~(UART_LSR_DR | UART_LSR_BI);
            }
            serial_update_irq(pThis);

This causes the interrupt to go to 0, and then the "serialNotifyRead" routine sets the interrupt back to 1. If the operating system uses interrupt edges, this allows a new edge to be generated to indicate that there is pending data.

In VirtualBox v6.1.30, the routine "uartRegRbrDllRead" (UartCore.cpp) could be modified like this:

        if (pThis->uRegFcr & UART_REG_FCR_FIFO_EN)
        {
        ... (equal) ...
        }
        else
        {
#ifndef IN_RING3
            /*
             * Only go back to R3 if there is new data available for the FIFO
             * and we would clear the interrupt to fill it up again.
             */
            if (ASMAtomicReadU32(&pThis->cbAvailRdr) > 1)
            {
                rc = VINF_IOM_R3_IOPORT_READ;
            }
#endif
            if (rc == VINF_SUCCESS)
            {
                *puVal = pThis->uRegRbr;

                /* Reset the Break bit. */
                UART_REG_CLR(pThis->uRegLsr, UART_REG_LSR_BI);

                /* Reset the DR bit. This allows a new interrupt edge. */
                UART_REG_CLR(pThis->uRegLsr, UART_REG_LSR_DR);

                uartIrqUpdate(pDevIns, pThis, pThisCC);

                if (ASMAtomicReadU32(&pThis->cbAvailRdr) > 0)
                {
                    Assert(pThis->cbAvailRdr);
                    uint32_t cbAvail = ASMAtomicDecU32(&pThis->cbAvailRdr);
                    if (cbAvail)
                    {
#ifndef IN_RING3
                        /* Restore state and go back to R3. */
                        ASMAtomicIncU32(&pThis->cbAvailRdr);
                        rc = VINF_IOM_R3_IOPORT_READ;
#else
                        /* Fetch new data and set the DR bit. */
                        uartR3DataFetch(pDevIns, pThis, pThisCC);
#endif
                    }
                }
            }
        }

Could you do a test build with this modification to see if it works?

Version 1, edited 2 years ago by FelixG (previous) (next) (diff)
Note: See TracTickets for help on using tickets.

© 2023 Oracle
ContactPrivacy policyTerms of Use