Log4OM

Hans,
Did you resolve this issue or do you still have problems?

It plays well most of the time but sometimes after a period of inactivity (hours, not minutes) the link to PSTRotator seems to die. Restarting Log4OM revives it.

K0HB wrote:It plays well most of the time but sometimes after a period of inactivity (hours, not minutes) the link to PSTRotator seems to die. Restarting Log4OM revives it.

In the communicator there is a log file.

Next time the PSTRotator connection is lost please do not restart the program, save the communicator log file and email it to me.

probably the connection is closed by one of the side, and Log4OM doesn't have a check to reconnect (it's an udp protocol and could stay idle for many hours)

Log will help

73
Daniele

G4POP wrote:

K0HB wrote:It plays well most of the time but sometimes after a period of inactivity (hours, not minutes) the link to PSTRotator seems to die. Restarting Log4OM revives it.

In the communicator there is a log file.

Next time the PSTRotator connection is lost please do not restart the program, save the communicator log file and email it to me.

Terry,

The situation just occurred here again. I have emailed a copy of the log file to your xxxx.arrl.net address.

Here is a copy of the log contents:

2013-10-09 05:22:42.1880 INFO: FormMain: Program started
2013-10-09 05:22:42.2120 INFO: FormMain: Log4OMCommunicator folder set: C:\Users\HANS\AppData\Roaming\LogOM\
2013-10-09 05:22:42.2130 INFO: FileManagement: CONFIG begin load
2013-10-09 05:22:42.2150 INFO: FileManagement: CONFIG load completed
2013-10-09 05:22:42.2290 INFO: FormMain: Starting Communicator Services
2013-10-09 05:22:42.2290 INFO: FormMain: Starting WCF Connection...
2013-10-09 05:22:50.8995 INFO: FormMain: WCF Connection started
2013-10-09 05:22:50.9005 INFO: FormMain: Starting TCP Connection with Log4OM...
2013-10-09 05:22:50.9035 INFO: TCPClientManager: Attempting TCP Connection with 127.0.0.1 port 8081
2013-10-09 05:22:50.9355 INFO: TCPClientManager: Connecting socket to 127.0.0.1:8081
2013-10-09 05:22:50.9365 INFO: TCPClientManager: TCP Connection with Log4OM started
2013-10-09 05:22:50.9415 INFO: TCPManagement: Starting PST Rotator Server on port 12040
2013-10-09 05:22:50.9425 WARN: NotificationManagement: Unable to start email polling. Email is not configured
2013-10-09 05:22:50.9475 INFO: NotificationManagement: Starting GROWL Service...
2013-10-09 05:22:50.9805 INFO: NotificationManagement: GROWL Service started
2013-10-09 05:22:50.9815 INFO: FormMain: ****** SERVICE STARTED *****
2013-10-09 05:22:51.0175 INFO: TCPClientManager: Connection established to 127.0.0.1:8081
2013-10-09 05:22:51.9826 ERROR: *** NotificationManagement: GROWL Error - 201 : The destination server was not reachable
2013-10-09 05:22:51.9846 ERROR: *** NotificationManagement: GROWL Error - 201 : The request failed to be sent successfully due to a network problem.
2013-10-09 05:22:51.9846 ERROR: *** NotificationManagement: GROWL Error - 201 : The response failed to be read successfully due to a network problem.
2013-10-09 05:23:09.5826 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 05:23:09.5856 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>283</AZIMUTH></PST>
2013-10-09 05:23:09.6066 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>V73NS</CALL></PST>
2013-10-09 05:23:09.6266 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 14:59:00.7002 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 14:59:00.7042 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>42</AZIMUTH></PST>
2013-10-09 14:59:00.7252 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>DL1AMQ</CALL></PST>
2013-10-09 14:59:00.7452 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 15:19:50.9777 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 15:19:50.9797 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>114</AZIMUTH></PST>
2013-10-09 15:19:50.9997 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>NL7VX</CALL></PST>
2013-10-09 15:19:51.0207 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 18:34:10.7186 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 18:34:10.7236 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>231</AZIMUTH></PST>
2013-10-09 18:34:10.7436 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>TX5D</CALL></PST>
2013-10-09 18:34:10.7636 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 18:35:04.3797 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 18:35:04.3837 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>231</AZIMUTH></PST>
2013-10-09 18:35:04.4047 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>TX5D</CALL></PST>
2013-10-09 18:35:04.4257 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 18:35:13.6012 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 18:35:13.6042 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>89</AZIMUTH></PST>
2013-10-09 18:35:13.6252 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>6V7T</CALL></PST>
2013-10-09 18:35:13.6462 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 18:35:35.4485 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 18:35:35.4525 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>231</AZIMUTH></PST>
2013-10-09 18:35:35.4735 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>TX5D</CALL></PST>
2013-10-09 18:35:35.4945 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 19:24:42.1910 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 19:24:42.1950 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>103</AZIMUTH></PST>
2013-10-09 19:24:42.2160 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>W8FJ</CALL></PST>
2013-10-09 19:24:42.2370 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 19:40:17.9936 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 19:40:17.9986 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>254</AZIMUTH></PST>
2013-10-09 19:40:18.0196 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>3D2GC</CALL></PST>
2013-10-09 19:40:18.0396 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 22:20:42.7651 ERROR: *** TCPClientManager: Error reading from socket: [SerializationException] Binary stream '0' does not contain a valid BinaryHeader. Possible causes are invalid stream or object version change between serialization and deserialization. ******* [Function: ClientSocket_PacketArrived] System.Runtime.Serialization.SerializationException: Binary stream '0' does not contain a valid BinaryHeader. Possible causes are invalid stream or object version change between serialization and deserialization.
at System.Runtime.Serialization.Formatters.Binary.__BinaryParser.Run()
at System.Runtime.Serialization.Formatters.Binary.ObjectReader.Deserialize(HeaderHandler handler, __BinaryParser serParser, Boolean fCheck, Boolean isCrossAppDomain, IMethodCallMessage methodCallMessage)
at System.Runtime.Serialization.Formatters.Binary.BinaryFormatter.Deserialize(Stream serializationStream, HeaderHandler handler, Boolean fCheck, Boolean isCrossAppDomain, IMethodCallMessage methodCallMessage)
at Messages.Util.Deserialize(Byte[] binaryObject)
at Log4OmCommunicator.TCPClient.TCPClientManager.ClientSocket_PacketArrived(AsyncResultEventArgs`1 e)
2013-10-09 22:20:42.8161 ERROR: *** TCPClientManager: Socket error during Read: [SocketException] A request to send or receive data was disallowed because the socket is not connected and (when sending on a datagram socket using a sendto call) no address was supplied

This is a job for Superman! BTW it's not Clark Kent it's Daniele

HELP LELE

2013-10-09 19:24:42.2160 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>W8FJ</CALL></PST>
2013-10-09 19:24:42.2370 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 19:40:17.9936 INFO: TCPManagement: BEGIN send PST Rotator Server message...
2013-10-09 19:40:17.9986 TRACE: TCPManagement: PST Rotator UDP Broadcast azimuth sent: <PST><AZIMUTH>254</AZIMUTH></PST>
2013-10-09 19:40:18.0196 TRACE: TCPManagement: PST Rotator UDP Broadcast call sent: <PST><CALL>3D2GC</CALL></PST>
2013-10-09 19:40:18.0396 INFO: TCPManagement: END send PST Rotator Server message...
2013-10-09 22:20:42.7651 ERROR: *** TCPClientManager: Error reading from socket: [SerializationException] Binary stream '0' does not contain a valid BinaryHeader. Possible causes are invalid stream or object version change between serialization and deserialization. ******* [Function: ClientSocket_PacketArrived] System.Runtime.Serialization.SerializationException: Binary stream '0' does not contain a valid BinaryHeader. Possible causes are invalid stream or object version change between serialization and deserialization.
at System.Runtime.Serialization.Formatters.Binary.__BinaryParser.Run()
at System.Runtime.Serialization.Formatters.Binary.ObjectReader.Deserialize(HeaderHandler handler, __BinaryParser serParser, Boolean fCheck, Boolean isCrossAppDomain, IMethodCallMessage methodCallMessage)
at System.Runtime.Serialization.Formatters.Binary.BinaryFormatter.Deserialize(Stream serializationStream, HeaderHandler handler, Boolean fCheck, Boolean isCrossAppDomain, IMethodCallMessage methodCallMessage)
at Messages.Util.Deserialize(Byte[] binaryObject)
at Log4OmCommunicator.TCPClient.TCPClientManager.ClientSocket_PacketArrived(AsyncResultEventArgs`1 e)
2013-10-09 22:20:42.8161 ERROR: *** TCPClientManager: Socket error during Read: [SocketException] A request to send or receive data was disallowed because the socket is not connected and (when sending on a datagram socket using a sendto call) no address was supplied

I'm investigating on the issue... seems to be very frequent on other user cases...

I hope i will deliver something in the next release

Hi everyone,

The issue of losing TCP connection affects not only the Rotator controller (PstRotator in my case) but also other processes like for example the logging feature of WSJT-X.

This TCP communication failure happens randomly. TCP com can be ON for 5 hours in a row, or be stopped several times in one hour without being related to a specific event or action.
I even considered that radio transmission might have an effet on the reliability of the TCP communication but I could not establish any link between these.

Instead of restarting Log4OM, if do as follows to restart the TCP com process:
I right-click on the red button which indicated that TCP communication has been stopped and select -> connect TCP
I get the message "Log4OM communicator. Application is already running" -> left-click on OK button
I open the communicator window and I see "Service status" (stopped), I click on the blue button "TCP communication to Log4OM" to turn the process on.
I click to reduce the communicator window (still present in the task bar) and then I resume my activities.

I would suggest to include into Log4OM a loop checking the TCP communication state. One could create a flag remembering the required state of TCP communication. This flag would be activated by the user setting. The current TCP communication state (ON/OFF) would be compared to the REQUIRED TCP communication state. In case of discrepancy, the current TCP communication state would be aligned with the desired state via a dedicated program sequence.

I believe that this could fix the issue, whatever its origin is (weakness of Window, or something else)

This TCP issue happened on several computers, either with W7, W8 or W10.

73 Philippe
F5FDV

Hi Philippe,
i'll check the communication stack. My first idea is to add a keep alive packet, but this solution can be added too.

Thanks
lele