Exception handling console input


#1

Since switching to mineos-node I find every few days all or most of the servers go offline
In their server logs they report the following:

[18:10:28] [Server console handler/ERROR]: Exception handling console input java.io.IOException: Input/output error at java.io.FileInputStream.readBytes(Native Method) ~[?:1.7.0_79] at java.io.FileInputStream.read(FileInputStream.java:272) ~[?:1.7.0_79] at java.io.BufferedInputStream.read1(BufferedInputStream.java:273) ~[?:1.7.0_79] at java.io.BufferedInputStream.read(BufferedInputStream.java:334) ~[?:1.7.0_79] at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) ~[?:1.7.0_79] at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) ~[?:1.7.0_79] at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) ~[?:1.7.0_79] at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[?:1.7.0_79] at java.io.BufferedReader.fill(BufferedReader.java:154) ~[?:1.7.0_79] at java.io.BufferedReader.readLine(BufferedReader.java:317) ~[?:1.7.0_79] at java.io.BufferedReader.readLine(BufferedReader.java:382) ~[?:1.7.0_79] at net.minecraft.server.dedicated.DedicatedServer$2.run(DedicatedServer.java:97) [pq.class:?]

anyone any ideas?
of course it might be nothing to do with mineos but Ubuntu that it’s running on


#2

Are there users other than yourself who log in to the webui?

Based on the error, it’s crashing based on something being sent to the console–which MineOS does. So the question is determining what is being sent when these things crash.

Are there indications of any user activity in the seconds leading up to the error?

MineOS doesn’t send any commands to the console except those that are scheduled. So are you scheduling a backup, for example? Or an archive? Both of these receive save-off and save-all commands prior to being backed up and archived. So is there a pattern between the crashes and either of these actions?


#3

Only one webui user (yes I hear that bus coming)
It seems to fall over at random times when I’m not logged into web ui

One clue though - I have scheduled archive create but it’s not working. Timing doesn’t seem related though as the cron entry for archive is “0 2 * * *” i.e. daily at 2am but the error above was at 18:00

If that archive was being started should I see anything from the save-off/save-all in the minecraft logs? (forge server)


#4

My *nix skills are rusty - I missed this - the mineos service is exiting and restarting
Marking the servers as start on boot largely mitigates this, but my poor little box still has something wrong

Sep 15 18:53:01 ns3007279 CRON[11211]: (root) CMD (/usr/local/rtm/bin/rtm 29 > /dev/null 2> /dev/null)
Sep 15 18:54:01 ns3007279 CRON[11271]: (root) CMD (/usr/local/rtm/bin/rtm 29 > /dev/null 2> /dev/null)
Sep 15 18:55:01 ns3007279 CRON[11324]: (root) CMD (/usr/local/rtm/bin/rtm 29 > /dev/null 2> /dev/null)
Sep 15 18:56:01 ns3007279 CRON[11380]: (root) CMD (/usr/local/rtm/bin/rtm 29 > /dev/null 2> /dev/null)
Sep 15 18:56:48 ns3007279 systemd[1]: mineos.service: main process exited, code=exited, status=1/FAILURE
Sep 15 18:56:48 ns3007279 node[11432]: mineos daemon is not running
Sep 15 18:58:01 ns3007279 CRON[11523]: (root) CMD (/usr/local/rtm/bin/rtm 29 > /dev/null 2> /dev/null)
Sep 15 18:58:18 ns3007279 systemd[1]: mineos.service stop-sigterm timed out. Killing.
Sep 15 18:58:18 ns3007279 systemd[1]: Unit mineos.service entered failed state.
Sep 15 18:58:18 ns3007279 systemd[1]: mineos.service failed.
Sep 15 18:58:19 ns3007279 systemd[1]: mineos.service holdoff time over, scheduling restart.
Sep 15 18:58:19 ns3007279 systemd[1]: Cannot add dependency job for unit lvm2-lvmetad.socket, ignoring: Unit lvm2-lvmetad.socket is masked.
Sep 15 18:58:19 ns3007279 systemd[1]: Cannot add dependency job for unit lvm2-monitor.service, ignoring: Unit lvm2-monitor.service is masked.
Sep 15 18:58:19 ns3007279 systemd[1]: Cannot add dependency job for unit dm-event.socket, ignoring: Unit dm-event.socket is masked.
Sep 15 18:58:19 ns3007279 systemd[1]: Starting Start MineOS minecraft front-end…
Sep 15 18:58:19 ns3007279 node[11567]: Starting mineos daemon…
Sep 15 18:58:19 ns3007279 node[11567]: mineos daemon started. PID: 11569
Sep 15 18:58:19 ns3007279 systemd[1]: Started Start MineOS minecraft front-end.
Sep 15 18:59:43 ns3007279 systemd[1]: Created slice user-0.slice.
Sep 15 18:59:43 ns3007279 systemd[1]: Starting user-0.slice.


#5

not sure if this is it dying or starting back up again

{“date”:“Tue Sep 15 2015 18:56:45 GMT+0100 (BST)”,“process”:{“pid”:6471,“uid”:0,“gid”:0,“cwd”:"/",“execPath”:"/usr/bin/nodejs",“version”:“v0.10.25”,“argv”:["/usr/bin/nodejs","/usr/games/minecraft/webui.js",“start”],“memoryUsage”:{“rss”:337911808,“heapTotal”:254325032,“heapUsed”:226005152}},“os”:{“loadavg”:[0.33642578125,0.35302734375,0.39990234375],“uptime”:2161573.152864687},“trace”:[{“column”:7,“file”:"/usr/games/minecraft/node_modules/fireworm/lib/file.js",“function”:null,“line”:45,“method”:null,“native”:false},{“column”:15,“file”:“fs.js”,“function”:“Object.oncomplete”,“line”:107,“method”:“oncomplete”,“native”:false}],“stack”:[“AssertionError: File should always be initialied with stat”," at /usr/games/minecraft/node_modules/fireworm/lib/file.js:45:7"," at Object.oncomplete (fs.js:107:15)"],“level”:“error”,“message”:“uncaughtException: File should always be initialied with stat”,“timestamp”:“2015-09-15T17:56:45.589Z”}

(repeated a few times)


#6

Most of these bugs are probably historical; i.e. fixed in earlier versions of Java. (But then you didn’t clearly specify which version you were talking about. How recent? Usual for who?). In addition to the reported bugs, there probably lots of ways that you could cause these errors to occur if you were prepared to interfere with the Java installation (e.g. tweak the “rt.jar” file) or mess around in native code. More about…Java Exceptions

Rino


#7

They’re definitely historical. v.0.10 of NodeJS is so old, it cannot be expected to work with the multitude of NPM modules that MineOS (and NodeJS in general) depend on.


#8