VirtualBox

Ticket #18668 (new defect)

Opened 2 years ago

Last modified 6 months ago

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

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

Change History

Changed 2 years ago by stagadet

Full log showing the errors

comment:1 Changed 2 years ago by aeichner

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 Changed 2 years ago by socratis

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 Changed 2 years ago by stagadet

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.

Changed 2 years ago by stagadet

Log of version 5.2.28 not showing serial related errors

comment:4 Changed 2 years ago by stagadet

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 Changed 2 years ago by vitaliy

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

comment:6 Changed 2 years ago by Solartrand

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 Changed 23 months ago by FelixG

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

Changed 23 months ago by FelixG

All ok with v5.2.26

Changed 23 months ago by FelixG

Nok with v6.1.0

comment:8 Changed 23 months ago by FelixG

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.

Changed 23 months ago by FelixG

comment:9 Changed 22 months ago by aeichner

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!

Changed 21 months ago by FelixG

Nok log with testbuild 6.1.3 - test 1

Changed 21 months ago by FelixG

Nok log with testbuild 6.1.3 - test 2

comment:10 Changed 21 months ago by FelixG

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 Changed 21 months ago by aeichner

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 Changed 21 months ago by FelixG

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 Changed 7 months ago by FelixG

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 Changed 6 months ago by aeichner

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

Note: See TracTickets for help on using tickets.

www.oracle.com
ContactPrivacy policyTerms of Use