Problem mit serieller Schnittstelle (overlapped) - CloseHandle returned nicht!

[_matze]

Hi,

ich habe momentan Probleme mit der seriellen Schnittstelle und hoffe, irgendwer hier kann mir eventuell einen Tipp geben. Ich steuere ein Gerät über einen USB-Seriell-Adapter an, und seit einer Weile gibt es bei einem Kunden das Problem, dass alle 1-2 Tage ein Fehler auftritt, den ich einfach nicht gelöst bekomme.

Ursprünglich hatte ich eine simple non-overlapped Kommunikation. Die hab ich irgendwann mal geschrieben und seit dem für alle Projekte verwendet. Hat immer geklappt, daher habe ich mir nie weiter Gedanken gemacht. Nun passiert beim Kunden aber folgendes - die Kommunikation scheint irgendwann gestört zu sein, es gibt einen Error 31 (A device attached to the system is not functioning.), und beim erneuten Versuch dann 5 (Access denied). Mein Ansatz war, das Handle einfach zu schließen und neu zu verbinden. Das klappt auch, wenn ich z.B. das USB-Kabel ziehe und wieder anstecke.

Aber bei diesem speziellen Fehler klappt es nicht, da CloseHandle blockiert! Sowas habe ich noch nie gesehen. CloseHandle kehrt einfach nie mehr zurück. Ein Kollege sagte, das liege sicher an der non-overlapped Kommunikation, und das das letzte ReadFile oder WriteFile intern noch blockiert. Also habe ich jetzt alles auf overlapped umgeschrieben. Leider ist das Resultat das gleiche. Ich kann die Verbindung nicht schließen, CloseHandle blockiert. Es passiert also folgendes:

- WriteFile wird aufgerufen (overlapped)
- WriteFile returned, GetLastError ist 5 (Access denied)
- Der WriteFile Aufruf ist damit sicher beendet, richtig? Da kann nichts mehr intern blockieren?

- Ich setze ein Event, um den Thread zu beenden, der parallel läuft und die Status Bits der seriellen Schnittstelle abfragt (WaitCommEvent).
- Ich warte auf Beenden des Threads mit WaitForSingleObject
- WAIT_OBJECT_0, Thread ist also beendet.
- Auch hier sehe ich keinen blockierenden Aufruf. WaitCommEvent (overlapped) ist returned (Event Mask ist 0x4, also EV_TXEMPTY, was ja auch kein schlechtes Zeichen ist), der Thread ist definitiv beendet.

- Jetzt rufe ich neuerdings sogar CancelIoEx auf, um eventuell ausstehende Anfragen zu beenden. GetLastError liefert 1168 (ERROR_NOT_FOUND), was mir doch sagen soll, dass keine Anfragen anstehen. Ist damit nicht quasi bewiesen, dass kein vorangegangenes Write-/ReadFile mehr intern blockiert, und die Verbindung eigentlich problemlos zu schließen sein sollte?

- Jetzt rufe ich CloseHandle auf, und es kehrt nie mehr zurück. Ich muss gestehen, ich bin ratlos.

Man muss sich hier natürlich auf fragen, warum dieser Fehler auftritt. Und warum nur an diesem einen System. Der Kunde hat noch zwei weitere Systeme ein paar Meter weiter stehen, und da gibt es den Fehler nicht. Es scheint also eine Hardware-Ursache zu sein. Lässt sich aber irgendwie nicht feststellen. Wir haben schon den Rechner, das Gerät, das Kabel und den USB-Seriell-Adapter getauscht. Eventuell ist es sogar ein EMV Problem? Wer weiß. Was auch immer die Ursache ist, es muss doch möglich sein, dies software-technisch zu lösen. Ich hoffe, irgendeiner von euch hat eine Idee, einen Tipp, einen guten Ratschlag - ich nehme, was ich kriegen kann!

Code:

int CSerialPort::Disconnect() {
	if (hEvExit) {
		Log(LogLevel_All, "set event hEvExit");
		SetEvent(hEvExit);
		DWORD wsfo = WaitForSingleObject(hStatusThread, 5000);
		if (wsfo == WAIT_OBJECT_0) {
			//thread ended
			Log(LogLevel_All, "Disconnect: WaitForSingleObject signaled, CommEventsThread ended");
		}
		else {
			Log(LogLevel_All, "Disconnect: WaitForSingleObject timed out for CommEventsThread");
		}
	}
	BOOL b;
	if (m_hCom && m_hCom != INVALID_HANDLE_VALUE) {
		Log(LogLevel_All, "Disconnect, before CancelIoEx");
		b = CancelIoEx(m_hCom, NULL);
		if (!b) {
			DWORD err = GetLastError();
			Log(LogLevel_Error, "GetLastError=%d", err);
		}
		Sleep(1000);
		Log(LogLevel_All, "Disconnect, before CloseHandle");
		b = CloseHandle(m_hCom);
		if (!b) {
			DWORD err = GetLastError();
			Log(LogLevel_Error, "GetLastError=%d", err);
		}
		Log(LogLevel_All, "Disconnect, after CloseHandle, returned %d", b);
		Sleep(1000);
		m_hCom = NULL;
		_ASSERTE(b);
	}

	if (hEvExit) { b = CloseHandle(hEvExit); hEvExit = NULL; _ASSERTE(b); }
	return 0;
}

Log:

2016_06_30 13_45_24 747	WriteFile
2016_06_30 13_45_24 747	WriteFile failed, but it isn't delayed. Error=5
2016_06_30 13_45_24 747	Reconnect
2016_06_30 13_45_24 747	set event hEvExit
2016_06_30 13_45_24 757	error=5
2016_06_30 13_45_24 757	CheckCommEventsThread: hvEvExit signaled
2016_06_30 13_45_24 757	Disconnect: WaitForSingleObject signaled, CommEventsThread ended
2016_06_30 13_45_24 757	Disconnect, before CancelIoEx
2016_06_30 13_45_24 757	GetLastError=1168
2016_06_30 13_45_25 757	Disconnect, before CloseHandle

(danach folgen mehrere Stunden andere Logeinträge; die Funktion blockiert also bis in alle Ewigkeit; das "Disconnect, after CloseHandle" kommt nie...)

[Andromeda]

Kann am Treiber liegen. Benutzt du RTS/CTS oder sowas? Falls ja, konfiguriere mal deine RS232 ohne Hardware-Handshake und schau, ob das Verhalten immer noch so ist.

Ansonsten siehe hier: https://social.msdn.microsoft.com/Forums/en-US/ce8ce1a3-64ed-4f26-b9ad-e2ff1d3be0a5/serial-port-hangs-whilst-closing?forum=Vsexpressvcs

...
One known way to get this behavior is to quickly close, then re-open the port. The next close hangs. Successful workarounds that have been reported are closing the port in another thread (odd one) and not closing the port. One thing I'd try is turning off the hardware handshake signals (RtsEnable and DtrEnable = False), then sleeping for a second or so to let any pending DataReceived events drain away.

[_matze]

Andromeda schrieb:

Kann am Treiber liegen. Benutzt du RTS/CTS oder sowas? Falls ja, konfiguriere mal deine RS232 ohne Hardware-Handshake und schau, ob das Verhalten immer noch so ist.

Ansonsten siehe hier: https://social.msdn.microsoft.com/Forums/en-US/ce8ce1a3-64ed-4f26-b9ad-e2ff1d3be0a5/serial-port-hangs-whilst-closing?forum=Vsexpressvcs

...
One known way to get this behavior is to quickly close, then re-open the port. The next close hangs. Successful workarounds that have been reported are closing the port in another thread (odd one) and not closing the port. One thing I'd try is turning off the hardware handshake signals (RtsEnable and DtrEnable = False), then sleeping for a second or so to let any pending DataReceived events drain away.

Nein, benutze kein RTS/CTS. Und soweit ich die Diskussion in deinem Link gelesen habe, geht es da um ein Problem mit der .Net-Klasse als ein grundsätzliches Problem mit der seriellen Schnittstelle, oder? Schnell schließen und sofort wieder öffnen mache ich auch nicht. Die Software läuft stunden- oder tagelang durch, bis dann plötzlich der Fehler wie beschrieben passiert. Das ist dann das erste Mal zur Laufzeit, dass ich versuche, den Port zu schließen.

[Andromeda]

Soweit ich weiß ist die RS232-Klasse bloß ein Wrapper um die WinAPI-Funktionen.

Der Fehler ist reproduzierbar, wie ich annehme?

Du schriebst: "Wir haben schon den Rechner, das Gerät, das Kabel und den USB-Seriell-Adapter getauscht."

^^ Und trotzdem ist der Fehler noch da, wenn du all diese Dinge tauschst?
Dann kann es ja nur Software sein. Entweder in deinem Programm, oder ein Bug im Treiber bzw. sonsteiner Windows-Systemkomponenten.

[_matze]

Andromeda schrieb:

Der Fehler ist reproduzierbar, wie ich annehme?

Na ja, reproduzierbar wär jetzt übertrieben. Es tritt nur bei diesem Kunden auf, und auch nur auf einem der drei Systeme (bei identischer Software, wohlgemerkt). Ich kann den Fehler nicht bei mir in der Firma reproduzieren, was die Fehlersuche ziemlich erschwert. Es tritt halt nur alle paar Tage beim Kunden auf. Und da dort die Produktion läuft und nicht gestört werden darf, kann ich auch nicht mal eben das System für einen Tag okkupieren.

Andromeda schrieb:

Du schriebst: "Wir haben schon den Rechner, das Gerät, das Kabel und den USB-Seriell-Adapter getauscht."

^^ Und trotzdem ist der Fehler noch da, wenn du all diese Dinge tauschst?
Dann kann es ja nur Software sein. Entweder in deinem Programm, oder ein Bug im Treiber bzw. sonsteiner Windows-Systemkomponenten.

Macht einerseits Sinn, andererseits läuft genau diese Software auf vielen anderen Systemen ja auch fehlerfrei. Neben dem problematischen System stehen noch zwei weitere, gerade mal ein paar Meter weiter. Die laufen. Vielleicht ist es ja echt sowas bescheuertes wie ein EMV-Problem, auch wenn ich nichts Verdächtiges in der Nähe sehe. Wir haben auch gar keine Messgeräte für sowas. Egal, das muss doch per Software lösbar sein. Was auch immer auf dem Port passiert, ich muss ihn doch schließen können.

EDIT: Treiber ist der gleiche wie auf den anderen Maschinen. Windows-Komponenten könnten schon sein (ich kann jetzt nicht sicher sagen, dass die Rechner hundertprozentig gleich sind; der Kunde hat ja eventuell was installiert, geupdated usw.). Aber da bin ich nicht sicher, wie ich das herausfinden soll.

Noch eine Ergänzung: wenn dieser Zustand eintritt, lässt sich der Prozess auch nicht mehr mit dem Taskmanager abschießen. Totaler Deadlock. Sobald ich das USB-Kabel ziehe, beendet er sich dann aber.

[Andromeda]

_matze schrieb:

Noch eine Ergänzung: wenn dieser Zustand eintritt, lässt sich der Prozess auch nicht mehr mit dem Taskmanager abschießen. Totaler Deadlock. Sobald ich das USB-Kabel ziehe, beendet er sich dann aber.

Versuch doch mal den USB-RS232-Treiber (ich glaube er heisst usbser.sys) zu disablen (über den Device Manager), wenn es mal wieder zu einem CloseHandle-Hänger gekommen ist. Vielleicht funktioniert es dann wieder. Falls ja, könntest du daraus einen Workaround basteln.

[Mox]

Was ist denn in Deinem Wandler für ein Chip verbaut? Hast Du zu Deinem Wandler mal den Treiber aktualisiert? Was verwendest Du für eine Strippe und wie lang ist diese? Ist das die 1€-Klasse bei 5m Länge, oder ist das was anständiges?

[_matze]

Andromeda schrieb:

_matze schrieb:

Noch eine Ergänzung: wenn dieser Zustand eintritt, lässt sich der Prozess auch nicht mehr mit dem Taskmanager abschießen. Totaler Deadlock. Sobald ich das USB-Kabel ziehe, beendet er sich dann aber.

Versuch doch mal den USB-RS232-Treiber (ich glaube er heisst usbser.sys) zu disablen (über den Device Manager), wenn es mal wieder zu einem CloseHandle-Hänger gekommen ist. Vielleicht funktioniert es dann wieder. Falls ja, könntest du daraus einen Workaround basteln.

Wird schwierig, da der Kunde meist nur eine E-Mail mit Logfiles und dem Inhalt "gestern in der Spätschicht wieder passiert" schickt. Bis ich davon erfahre, ist das System längst wieder neugestartet. Aber sollte sich die Gelegenheit ergeben, versuch ich's mal. Schon mal danke für deine Hilfe soweit.

[_matze]

Mox schrieb:

Was ist denn in Deinem Wandler für ein Chip verbaut? Hast Du zu Deinem Wandler mal den Treiber aktualisiert? Was verwendest Du für eine Strippe und wie lang ist diese? Ist das die 1€-Klasse bei 5m Länge, oder ist das was anständiges?

Das ist ein FTDI-Chip. Die Treiber sind die gleichen wie auf allen Systemen, aber du hast Recht. Ich könnte mal schauen, ob es eine neue Version gibt. Ich glaube, wir kaufen schon halbwegs anständige USB-Kabel.

[Andromeda]

_matze schrieb:

Schon mal danke für deine Hilfe soweit.

Gern geschehen.

Wenn du möchtest, dann poste bitte mal die Initialisierungssequenz, mit der du die RS232 "scharf" schaltest. Vielleicht lässt sich daran irgendeine Merkwürdigkeit erkennen.

[_matze]

Andromeda schrieb:

_matze schrieb:

Schon mal danke für deine Hilfe soweit.

Gern geschehen.

Wenn du möchtest, dann poste bitte mal die Initialisierungssequenz, mit der du die RS232 "scharf" schaltest. Vielleicht lässt sich daran irgendeine Merkwürdigkeit erkennen.

Die ist ziemlich wüst (und unfertig, wie das ganze Projekt), aber gut. ^^ Vielleicht findet sich ja was.

int CSerialPort::Connect() {
	if (m_hCom != INVALID_HANDLE_VALUE && m_hCom != nullptr) {
		Disconnect();
	}

	int portNumber = 0;
	for (int i = 0; i < 2; ++i) {
		FindSerialPort(
			m_Parameters.Baudrate,
			m_Parameters.StopBits,
			m_Parameters.Parity,
			m_Parameters.ByteSize,
			m_Parameters.SearchSettings[i].cmd,
			m_Parameters.SearchSettings[i].cmdLen,
			m_Parameters.SearchSettings[i].expectedAnswer,
			m_Parameters.SearchSettings[i].answerOffset,
			m_Parameters.SearchSettings[i].answerLen,
			&m_Parameters.PortNumber,
			m_Parameters.SearchSettings[i].dlgHeadline,
			m_Parameters.SearchSettings[i].tryCount);
		if ((m_Parameters.PortNumber > 0) || (m_Parameters.SearchSettings[i + 1].cmdLen == 0)) {
			//port found or no second set available
			break;
		}
	}

	m_hCom = CreateFile(PortNumberToDeviceString(m_Parameters.PortNumber), GENERIC_READ | GENERIC_WRITE, 0, 0, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL | FILE_FLAG_OVERLAPPED, 0);

	DCB dcb = { 0, };
	dcb.DCBlength = sizeof(dcb);
	BOOL b;
	b = GetCommState(m_hCom, &dcb);
	dcb.BaudRate = m_Parameters.Baudrate;
	dcb.ByteSize = BYTE(m_Parameters.ByteSize);
	dcb.StopBits = BYTE(m_Parameters.StopBits);
	dcb.Parity = BYTE(m_Parameters.Parity);
	dcb.XonLim = 0;
	dcb.XoffLim = 0;
	dcb.fParity = TRUE;
	dcb.fAbortOnError = FALSE;//Any Error -> ERROR_IO_ABORTED, ClearCommError
	b = SetCommState(m_hCom, &dcb); ////CHKRESRTN(!b, "SetCommState failed with code %d", FC_COMPortGeneral);
	COMMTIMEOUTS timeouts;
	timeouts.ReadIntervalTimeout = 1;//MAXDWORD; 
	timeouts.ReadTotalTimeoutMultiplier = 0;
	timeouts.ReadTotalTimeoutConstant = 0;
	timeouts.WriteTotalTimeoutMultiplier = 0;
	timeouts.WriteTotalTimeoutConstant = 0;
	b = SetCommTimeouts(m_hCom, &timeouts);	////CHKRESRTN(!b, "SetCommTimeouts failed with code %d", FC_COMPortGeneral);
	b = SetupComm(m_hCom, MAX_READ_BUFFER, MAX_WRITE_BUFFER); ////CHKRESRTN(!b, "SetupComm failed with code %d", FC_COMPortGeneral);
	b = EscapeCommFunction(m_hCom, SETDTR); ////CHKRESRTN(!b, "EscapeCommFunction failed with code %d", FC_COMPortGeneral);
	b = SetCommMask(m_hCom, EV_BREAK | EV_CTS | EV_DSR | EV_ERR | EV_RING | EV_RLSD | EV_RXCHAR | EV_RXFLAG | EV_TXEMPTY); //CHKRESRTN(!b, "SetCommMask failed with code %d", FC_COMPortGeneral);
	hEvExit = CreateEvent(NULL, TRUE, FALSE, NULL);
	Log(LogLevel_All, "start thread CheckCommEventsThread");
	hStatusThread = (HANDLE)_beginthreadex(0, 0, CheckCommEventsThread, this, 0, 0);

	return 0;
}

[Andromeda]

Was mir noch einfällt: rufst du irgendwo diese Funktion auf: https://msdn.microsoft.com/en-us/library/windows/desktop/aa363180(v=vs.85).aspx ?

Das sollte man tun, wenn ein Übertragungsfehler aufgetreten ist.

[Mox]

_matze schrieb:

Das ist ein FTDI-Chip.

Welche, Full Speed oder Hi-Speed? Für letztere brauchst Du unter Umständen bessere USB-Strippen!

_matze schrieb:

Die Treiber sind die gleichen wie auf allen Systemen, aber du hast Recht. Ich könnte mal schauen, ob es eine neue Version gibt.

Schaden kann das nicht. Hoffentlich sind das auch orginale FTDIs, sonst...

_matze schrieb:

Ich glaube, wir kaufen schon halbwegs anständige USB-Kabel.

Zeritifzierte?

[Mox]

_matze schrieb:

Die ist ziemlich wüst (und unfertig,

Vor allem unfertig. Du bist doch bereits in der ersten Antwort auf Flusskontrolle angesprochen worden...

Du musst den DCB schon komplett initialisieren. Das machst Du nicht, und das ist ein Fehler!

[Mox]

Andromeda schrieb:

Das sollte man tun, wenn ein Übertragungsfehler aufgetreten ist.

Soweit die Theorie. Praktisch kommt das nur bei Dir vor.

[Andromeda]

Mox schrieb:

Andromeda schrieb:

Das sollte man tun, wenn ein Übertragungsfehler aufgetreten ist.

Soweit die Theorie. Praktisch kommt das nur bei Dir vor.

Nope; prinzipiell ist der RS232-Treiber eine State-Machine. Gibts 'nen Bus-Error macht er dicht. Und das kann sich durchaus auch darin äußern, dass man ein Handle nicht closen kann. Matze sollte das einfach mal checken.

[Andromeda]

Mox schrieb:

Du musst den DCB schon komplett initialisieren. Das machst Du nicht

Macht er schon, denn er setzt ihn auf 0.

[Mox]

Andromeda schrieb:

Macht er schon, denn er setzt ihn auf 0.

Und überschreibt das gleich wieder mit dem Ist-Zustand:

b = GetCommState(m_hCom, &dcb);

[Mox]

Andromeda schrieb:

Nope; prinzipiell ist der RS232-Treiber eine State-Machine. Gibts 'nen Bus-Error macht er dicht. Und das kann sich durchaus auch darin äußern, dass man ein Handle nicht closen kann. Matze sollte das einfach mal checken.

Bus-Error? Es geht hier um RS232. Und nach irgendwelchen Übertragungsfehlern kannst du das Handle immer schließen. Wenn das nicht funktioniert, geht was ganz anderes schief. ClearCommError hilft Dir in diesem Falle auch nicht.

[_matze]

Mox schrieb:

Bus-Error? Es geht hier um RS232. Und nach irgendwelchen Übertragungsfehlern kannst du das Handle immer schließen. Wenn das nicht funktioniert, geht was ganz anderes schief. ClearCommError hilft Dir in diesem Falle auch nicht.

Die Frage ist, was das sein könnte.

Mit dem DCB hast du Recht. Werde ich korrigieren. Das ist aber sicher nicht das eigentliche Problem, oder?

Ich habe momentan einen Test hier im Büro laufen. Fast 500000 Kommunikationsversuche, alle erfolgreich. Ich kann das USB-Kabel ziehen und wieder dranstecken, und das Weiderverbinden funktioniert problemlos. Ich kriege dann halt Access Denied, dann suche ich mir wieder den richtigen COM-Port raus und es geht anstandslos weiter. Was zur Hölle passiert da beim Kunden? ^^