Invalid XML character was found in the CDATA section

[Tom-Willemsen]

Found when I left IBEX running over a weekend. Potentially related to #2090

...
*2017-02-17 16:51:09.584 [main] INFO  uk.ac.stfc.isis.ibex.ui.PerspectiveSwitcher - Switching to: uk.ac.stfc.isis.ibex.ui.devicescreens.perspective
*2017-02-17 16:51:18.905 [PVMgr Worker 2] INFO  uk.ac.stfc.isis.ibex.configserver.Configurations - Server status value: 
[Fatal Error] :1:68: An invalid XML character (Unicode: 0x1) was found in the CDATA section.
*2017-02-18 00:55:54.270 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x1) was found in the CDATA section.
[Fatal Error] :1:74: An invalid XML character (Unicode: 0x8) was found in the CDATA section.
*2017-02-18 00:55:54.281 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x8) was found in the CDATA section.
[Fatal Error] :1:68: An invalid XML character (Unicode: 0x0) was found in the CDATA section.
*2017-02-18 00:55:54.282 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x0) was found in the CDATA section.
[Fatal Error] :1:68: An invalid XML character (Unicode: 0x1) was found in the CDATA section.
[Fatal Error] :1:74: An invalid XML character (Unicode: 0x8) was found in the CDATA section.
[Fatal Error] :1:68: An invalid XML character (Unicode: 0x0) was found in the CDATA section.
*2017-02-18 00:55:58.267 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x1) was found in the CDATA section.
*2017-02-18 00:55:58.268 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x8) was found in the CDATA section.
*2017-02-18 00:55:58.270 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x0) was found in the CDATA section.
[Fatal Error] :1:68: An invalid XML character (Unicode: 0x0) was found in the CDATA section.
*2017-02-18 00:56:29.265 [Worker-1] ERROR uk.ac.stfc.isis.ibex.log.jms.XmlLogMessageParser - Error parsing IOC log message XML root element: An invalid XML character (Unicode: 0x0) was found in the CDATA section.
...

XML parser errors should be caught and handled gracefully rather than coming up as [FATAL].

Note: The Ibex GUI didn't actually crash because of these errors.

[FreddieAkeroyd]

I am wondering who is sending these - I looked at the IOC code and it checks all message characters sent with isascii(c) && (isprint(c) || isspace(c)) so unless there is some corruption in transit, its not coming from an IOC.

[Tom-Willemsen]

I had a look in my logs at the relevant time, and found this in the blockserver log:

[Sat Feb 18 00:55:15 2017] ----------------------------------------
[Sat Feb 18 00:55:15 2017] Exception happened during processing of request from ('130.246.132.163', 33444)
[Sat Feb 18 00:55:15 2017] Traceback (most recent call last):

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\SocketServer.py", line 295, in _handle_request_noblock

[Sat Feb 18 00:55:15 2017]     self.process_request(request, client_address)

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\SocketServer.py", line 321, in process_request

[Sat Feb 18 00:55:15 2017]     self.finish_request(request, client_address)

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\SocketServer.py", line 334, in finish_request

[Sat Feb 18 00:55:15 2017]     self.RequestHandlerClass(request, client_address, self)

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\SocketServer.py", line 651, in __init__

[Sat Feb 18 00:55:15 2017]     self.handle()

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\BaseHTTPServer.py", line 340, in handle

[Sat Feb 18 00:55:15 2017]     self.handle_one_request()

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\BaseHTTPServer.py", line 310, in handle_one_request

[Sat Feb 18 00:55:15 2017]     self.raw_requestline = self.rfile.readline(65537)

[Sat Feb 18 00:55:15 2017]   File "C:\Instrument\Apps\Python\lib\socket.py", line 476, in readline

[Sat Feb 18 00:55:15 2017]     data = self._sock.recv(self._rbufsize)

[Sat Feb 18 00:55:15 2017] error: [Errno 10054] An existing connection was forcibly closed by the remote host

[Sat Feb 18 00:55:15 2017] ----------------------------------------

And this was the IOC log:

[Sat Feb 18 00:55:31 2017] IOC Client 130.246.132.163:40718 connected

[Sat Feb 18 00:55:31 2017] Lost connection with client at 130.246.132.163:40718

[Sat Feb 18 00:55:31 2017] IOC Client 130.246.132.163:40718 disconnected

[Sat Feb 18 00:55:39 2017] IOC Client 130.246.132.163:48622 connected

[Sat Feb 18 00:55:39 2017] Lost connection with client at 130.246.132.163:48622

[Sat Feb 18 00:55:39 2017] IOC Client 130.246.132.163:48622 disconnected

[Sat Feb 18 00:55:53 2017] IOC Client 130.246.132.163:42848 connected

[Sat Feb 18 00:55:53 2017] Database error, error: 'Message Type "-" not recognised' Will retry.

[Sat Feb 18 00:55:54 2017] Database error, error: 'Message Type "-" not recognised' Will retry.

[Sat Feb 18 00:55:55 2017] Database error, error: 'Message Type "-" not recognised' Will retry.

[Sat Feb 18 00:55:56 2017] Database error, error: 'Message Type "-" not recognised' Will retry.

[continues for thousands of lines]

And before you ask, no I wasn't doing anything to IBEX at 1am on a Saturday ;)

[FreddieAkeroyd]

130.246.132.163 is vssscan1.rl.ac.uk so you were being scanned!

[Tom-Willemsen]

Thanks for clearing that up then Freddie, that's where the mystery messages are coming from!

Automated scans ~probably~ definitely shouldn't be breaking IBEX though...

[FreddieAkeroyd]

Similar message to #3240 but probably not related?