Official Fulqrum Publishing forum

Official Fulqrum Publishing forum (http://forum.fulqrumpublishing.com/index.php)
-   Daidalos Team discussions (http://forum.fulqrumpublishing.com/forumdisplay.php?f=202)
-   -   Il-2 Dedicated Server mission load problems (http://forum.fulqrumpublishing.com/showthread.php?t=41703)

TheGrunch 02-17-2014 12:07 AM

Il-2 Dedicated Server mission load problems
 
Hi guys,
Would really appreciate some help on an issue I am having getting missions to load with the Il-2 DS.

Free Saitek Aviator (PS3 version, postage paid) to the person who finds the solution to this issue, no matter how stupid or trivial it turns out to be.

I am writing a server controller in Clojure and Java using the JavaFX toolkit as the UI (original thread here).

The problem is that missions entered manually by the user into a text field seem to load fine all the time, however:

Missions selected by a file chooser dialog fail every time, but only the first time. Then they work every time, until you select a different mission with the file chooser dialog, whereupon they fail again, but only the first time. YouTube video here.

I just cannot find the solution to this bug! It's driving me insane! I have compared the two LOAD commands using the same mission from the text field and from the file chooser with a huge variety of different methods.

I've tried searching for hidden characters (both Unicode and ASCII non-printable, hidden or whitespace), changing the new line separator from \r\n to \n and even to \n\r\n, explicitly flushing my Writer even though I use a writer with autoflush on newline characters, and a number of different path normalisation, canonisation and relativisation methods.

Java String comparison shows that the LOAD commands I am using are the same, Wireshark TCP data is the same, logs on the server side show that the characters received are the same:

Manual
File Chooser

Code:

[Feb 17, 2014 12:29:15 AM] ------------ BEGIN log session -------------
[12:29:18 AM]        1>server NAME IL-2 Dedicated Server Linux 4.12m PWD
[12:29:18 AM]        1>difficulty SeparateEStart 1
[12:29:18 AM]        1>difficulty ComplexEManagement 1
[12:29:18 AM]        1>difficulty EngineOverheat 1
[12:29:18 AM]        1>difficulty TorqueGyroEffects 1
[12:29:18 AM]        1>difficulty FlutterEffect 1
[12:29:18 AM]        1>difficulty WindTurbulence 1
[12:29:18 AM]        1>difficulty StallsSpins 1
[12:29:18 AM]        1>difficulty Vulnerability 1
[12:29:18 AM]        1>difficulty BlackoutsRedouts 1
[12:29:18 AM]        1>difficulty RealisticGunnery 1
[12:29:18 AM]        1>difficulty LimitedFuel 1
[12:29:18 AM]        1>difficulty LimitedAmmo 1
[12:29:18 AM]        1>difficulty HeadShake 1
[12:29:18 AM]        1>difficulty CockpitAlwaysOn 1
[12:29:18 AM]        1>difficulty NoInstantSuccess 1
[12:29:18 AM]        1>difficulty Clouds 1
[12:29:18 AM]        1>difficulty RealisticLandings 1
[12:29:18 AM]        1>difficulty TakeoffLanding 1
[12:29:18 AM]        1>difficulty NoPadlock 1
[12:29:18 AM]        1>difficulty NoMapIcons 1
[12:29:18 AM]        1>difficulty NoMinimapPath 1
[12:29:18 AM]        1>difficulty NoSpeedBar 0
[12:29:18 AM]        1>difficulty NoOutsideViews 0
[12:29:18 AM]        1>difficulty NoIcons 0
[12:29:18 AM]        1>maxping 9999 DELAY 9999 WARNINGS 9999
[12:29:18 AM]        1>mp_dotrange FOE COLOR 100 DOT 100 RANGE 100 TYPE 100 ID 100 NAME 100
[12:29:18 AM]        1>mp_dotrange FRIENDLY COLOR 100 DOT 100 RANGE 100 TYPE 100 ID 100 NAME 100
[12:29:18 AM]        33>[12:30:39 AM]        server
[12:30:39 AM]        Type: Local server
[12:30:39 AM]        Name: IL-2 Dedicated Server Linux 4.12m
[12:30:39 AM]        Description:
[12:30:39 AM]        34>[12:30:39 AM]        mission
[12:30:39 AM]        Mission NOT loaded
[12:30:39 AM]        35>[12:31:04 AM]        mission LOAD Net/dogfight/DCG/dcgmission.mis
[12:31:04 AM]        Loading mission Net/dogfight/DCG/dcgmission.mis...
[12:31:04 AM]        Load bridges
[12:31:04 AM]        Load static objects
[12:31:08 AM]        Mission: Net/dogfight/DCG/dcgmission.mis is Loaded

[12:31:08 AM]        36>[12:31:17 AM]        mission DESTROY
[12:31:18 AM]        37>[12:31:18 AM]        mission
[12:31:18 AM]        Mission NOT loaded
[12:31:18 AM]        38>[12:31:19 AM]        mission LOAD FBDj/dcgmission.mis
[12:31:19 AM]        SectFile load failed: null
[12:31:19 AM]        java.io.FileNotFoundException
[12:31:19 AM]                at com.maddox.rts.SFSInputStream.<init>(SFSInputStream.java:65)
[12:31:19 AM]                at com.maddox.rts.SFSReader.<init>(SFSReader.java:19)
[12:31:19 AM]                at com.maddox.rts.SectFile.loadFile(SectFile.java:227)
[12:31:19 AM]                at com.maddox.rts.SectFile.loadFile(SectFile.java:154)
[12:31:19 AM]                at com.maddox.rts.SectFile.<init>(SectFile.java:126)
[12:31:19 AM]                at com.maddox.rts.SectFile.<init>(SectFile.java:86)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:333)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:321)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:318)
[12:31:19 AM]                at com.maddox.il2.game.cmd.CmdMission.exec(CmdMission.java:65)
[12:31:19 AM]                at com.maddox.rts.CmdEnv.exec(CmdEnv.java:601)
[12:31:19 AM]                at com.maddox.il2.game.DServer.loopApp(DServer.java:172)
[12:31:19 AM]                at com.maddox.il2.game.Main.exec(Main.java:439)
[12:31:19 AM]                at com.maddox.il2.game.DServer.main(DServer.java:436)
[12:31:19 AM]        Loading mission FBDj/dcgmission.mis...
[12:31:19 AM]        No MAP in mission file
[12:31:19 AM]        java.lang.Exception: No MAP in mission file
[12:31:19 AM]                at com.maddox.il2.game.Mission.loadMain(Mission.java:765)
[12:31:19 AM]                at com.maddox.il2.game.Mission._load(Mission.java:476)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:426)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:334)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:321)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:318)
[12:31:19 AM]                at com.maddox.il2.game.cmd.CmdMission.exec(CmdMission.java:65)
[12:31:19 AM]                at com.maddox.rts.CmdEnv.exec(CmdEnv.java:601)
[12:31:19 AM]                at com.maddox.il2.game.DServer.loopApp(DServer.java:172)
[12:31:19 AM]                at com.maddox.il2.game.Main.exec(Main.java:439)
[12:31:19 AM]                at com.maddox.il2.game.DServer.main(DServer.java:436)
[12:31:19 AM]        No MAP in mission file
[12:31:19 AM]        java.lang.Exception: No MAP in mission file
[12:31:19 AM]                at com.maddox.il2.game.Mission.loadMain(Mission.java:765)
[12:31:19 AM]                at com.maddox.il2.game.Mission._load(Mission.java:476)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:426)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:334)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:321)
[12:31:19 AM]                at com.maddox.il2.game.Mission.load(Mission.java:318)
[12:31:19 AM]                at com.maddox.il2.game.cmd.CmdMission.exec(CmdMission.java:65)
[12:31:19 AM]                at com.maddox.rts.CmdEnv.exec(CmdEnv.java:601)
[12:31:19 AM]                at com.maddox.il2.game.DServer.loopApp(DServer.java:172)
[12:31:19 AM]                at com.maddox.il2.game.Main.exec(Main.java:439)
[12:31:19 AM]                at com.maddox.il2.game.DServer.main(DServer.java:436)
[12:31:19 AM]        ERROR mission: FBDj/dcgmission.mis  NOT loaded [java.lang.Exception: No MAP in mission file ]
[12:31:19 AM]        39>[12:31:29 AM]        mission LOAD FBDj/dcgmission.mis
[12:31:29 AM]        Loading mission FBDj/dcgmission.mis...
[12:31:29 AM]        Load bridges
[12:31:29 AM]        Load static objects
[12:31:32 AM]        Mission: FBDj/dcgmission.mis is Loaded
[12:31:32 AM]        40>[12:31:57 AM]        mission DESTROY
[12:31:57 AM]        41>[12:31:57 AM]        mission
[12:31:57 AM]        Mission NOT loaded
[12:31:57 AM]        42>[12:31:58 AM]        mission LOAD Net/dogfight/DCG/dcgmission.mis
[12:31:58 AM]        SectFile load failed: null
[12:31:58 AM]        java.io.FileNotFoundException
[12:31:58 AM]                at com.maddox.rts.SFSInputStream.<init>(SFSInputStream.java:65)
[12:31:58 AM]                at com.maddox.rts.SFSReader.<init>(SFSReader.java:19)
[12:31:58 AM]                at com.maddox.rts.SectFile.loadFile(SectFile.java:227)
[12:31:58 AM]                at com.maddox.rts.SectFile.loadFile(SectFile.java:154)
[12:31:58 AM]                at com.maddox.rts.SectFile.<init>(SectFile.java:126)
[12:31:58 AM]                at com.maddox.rts.SectFile.<init>(SectFile.java:86)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:333)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:321)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:318)
[12:31:58 AM]                at com.maddox.il2.game.cmd.CmdMission.exec(CmdMission.java:65)
[12:31:58 AM]                at com.maddox.rts.CmdEnv.exec(CmdEnv.java:601)
[12:31:58 AM]                at com.maddox.il2.game.DServer.loopApp(DServer.java:172)
[12:31:58 AM]                at com.maddox.il2.game.Main.exec(Main.java:439)
[12:31:58 AM]                at com.maddox.il2.game.DServer.main(DServer.java:436)
[12:31:58 AM]        Loading mission Net/dogfight/DCG/dcgmission.mis...
[12:31:58 AM]        No MAP in mission file
[12:31:58 AM]        java.lang.Exception: No MAP in mission file
[12:31:58 AM]                at com.maddox.il2.game.Mission.loadMain(Mission.java:765)
[12:31:58 AM]                at com.maddox.il2.game.Mission._load(Mission.java:476)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:426)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:334)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:321)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:318)
[12:31:58 AM]                at com.maddox.il2.game.cmd.CmdMission.exec(CmdMission.java:65)
[12:31:58 AM]                at com.maddox.rts.CmdEnv.exec(CmdEnv.java:601)
[12:31:58 AM]                at com.maddox.il2.game.DServer.loopApp(DServer.java:172)
[12:31:58 AM]                at com.maddox.il2.game.Main.exec(Main.java:439)
[12:31:58 AM]                at com.maddox.il2.game.DServer.main(DServer.java:436)
[12:31:58 AM]        No MAP in mission file
[12:31:58 AM]        java.lang.Exception: No MAP in mission file
[12:31:58 AM]                at com.maddox.il2.game.Mission.loadMain(Mission.java:765)
[12:31:58 AM]                at com.maddox.il2.game.Mission._load(Mission.java:476)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:426)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:334)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:321)
[12:31:58 AM]                at com.maddox.il2.game.Mission.load(Mission.java:318)
[12:31:58 AM]                at com.maddox.il2.game.cmd.CmdMission.exec(CmdMission.java:65)
[12:31:58 AM]                at com.maddox.rts.CmdEnv.exec(CmdEnv.java:601)
[12:31:58 AM]                at com.maddox.il2.game.DServer.loopApp(DServer.java:172)
[12:31:58 AM]                at com.maddox.il2.game.Main.exec(Main.java:439)
[12:31:58 AM]                at com.maddox.il2.game.DServer.main(DServer.java:436)
[12:31:58 AM]        ERROR mission: Net/dogfight/DCG/dcgmission.mis  NOT loaded [java.lang.Exception: No MAP in mission file ]
[12:31:58 AM]        43>[12:32:02 AM]        mission LOAD Net/dogfight/DCG/dcgmission.mis
[12:32:03 AM]        Loading mission Net/dogfight/DCG/dcgmission.mis...
[12:32:03 AM]        Load bridges
[12:32:03 AM]        Load static objects
[12:32:05 AM]        Mission: Net/dogfight/DCG/dcgmission.mis is Loaded

[12:32:05 AM]        44>[12:33:29 AM]        mission DESTROY
[12:33:30 AM]        45>[12:33:30 AM]        mission
[12:33:30 AM]        Mission NOT loaded
[12:33:30 AM]        46>[12:33:31 AM]        mission LOAD FBDj/dcgmission.mis
[12:33:31 AM]        Loading mission FBDj/dcgmission.mis...
[12:33:31 AM]        Load bridges
[12:33:31 AM]        Load static objects
[12:33:33 AM]        Mission: FBDj/dcgmission.mis is Loaded
[12:33:33 AM]        47>[12:33:41 AM]        mission DESTROY
[12:33:42 AM]        48>[12:33:42 AM]        mission
[12:33:42 AM]        Mission NOT loaded
[12:33:42 AM]        49>[12:33:42 AM]        mission LOAD Net/dogfight/DCG/dcgmission.mis
[12:33:43 AM]        Loading mission Net/dogfight/DCG/dcgmission.mis...
[12:33:43 AM]        Load bridges
[12:33:43 AM]        Load static objects
[12:33:45 AM]        Mission: Net/dogfight/DCG/dcgmission.mis is Loaded

[12:33:45 AM]        50>

As you can see, the commands that were sent in the blue highlighted section were to all appearances the same. However, the response of the server was completely different.

What can possibly cause sending the same command to the IL-2 DS and getting different results? Could this be a character encoding issue?

How is it possible to send the same LOAD command to the server and it will fail the first time, every time, then succeed the second and all subsequent times until another mission is chosen?

Would really appreciate any help or advice with this problem as I'd love to continue with this development.

Pfeil 02-17-2014 02:27 AM

Without insight into the source code, it's nigh impossible to diagnose this.

It could have something to do with how the file dialog returns the path, it could be a windows->Linux(like you said, encoding) issue, it could be a ridiculous number of things without knowing how the program actually works.

I'd like to see the code that retrieves values from the textbox and the file chooser at least, the difference is likely to be there, as by the way you describe it they do the same thing(I'm assuming here the file is always on the server, you're just getting the location in different ways, correct?).

The_WOZ 02-17-2014 03:00 AM

Seems to be some kind of problem with relative paths

Long shot but try running the dedicated server through strace.

For example:

strace -e open <name of the dedicated server executable>

that will print a line for every file the dedicated server tries to open.

TheGrunch 02-17-2014 12:00 PM

Pfeil, thanks for taking an interest! The relevant code is as follows:

Server path chooser; this is a javafx.stage.FileChooser instance, which returns a java.io.File object. The UI objects are retrieved from a map of controls by key and "file" is bound to the results of showing the file chooser dialog using the .showOpenDialog method (this is all that is in ui/show-chooser). This is just to keep the UI and the application logic separate. The file is then converted to an absolute path String using File.getCanonicalPath.
Code:

(defn server-choose-command
  "### server-choose-command
  This zero argument function displays the server chooser dialog and uses
  the provided file to set the server path in the UI."
  []
  (let [{:keys [server-chooser
                server-path-lbl]} @state/controls
        file (ui/show-chooser server-chooser)]
    (when file
      (ui/set-label server-path-lbl (.getCanonicalPath file)))))

A javafx.beans.InvalidationListener has been set over the TextProperty of the javafx.scene.control.Label which updates an atom (Clojure thread-safe mutable var) in order to store the server path as a globally accessible state variable.
Code:

(defn server-path-select
  []
  (let [{:keys [server-path-lbl]} @state/controls
        server-path (ui/get-text server-path-lbl)]
    (if (= server-path "...")
      (reset! state/server-path nil)
      (reset! state/server-path server-path))))

The get-text function is below:
Code:

(defn get-text
  "### get-text
  This one argument function returns the text from the supplied control."
  ^String [control]
  (.getText control))

This function sets the value of the mission path label from the javafx.scene.control.TextField object, and is triggered by a javafx.event.EventHandler set on the Select button.
Code:

(defn set-single-remote
  []
  (let [{:keys [single-path-fld single-path-lbl]} @state/controls
        mission-path (ui/get-text single-path-fld)]
    (when (not (string/blank? mission-path))
      (ui/set-label single-path-lbl mission-path))))

UI code which sets the label text below:
Code:

(defn set-label
  "### set-label
  This two argument function sets the text content of the supplied control to the
  value of the supplied text argument."
  [^Label label text]
  (.setText label text))

Much like the server chooser, the single mission chooser function retrieves a File object from user input, turns it into an absolute path String and puts it into the single mission path Label object. The difference in this case is that the canonical path of the file is resolved against the content of the global server path atom.
Code:

(defn single-choose-command
  []
  (let [{:keys [mis-chooser
                single-path-lbl]} @state/controls
        file (ui/show-chooser mis-chooser)]
    (when file
      (ui/set-label single-path-lbl
                    (get-resolved-path @state/server-path (.getCanonicalPath file))))))

The code to resolve the path transforms the input Strings into Path objects using Paths.get from java.nio.file.Paths. It gets the parent folder of the server .exe file and then resolves this against "Missions" to get the root missions directory.
Then the path is relativized against the missions directory, normalised to remove any redundant elements and converted to a String object, before replacing all backward slash characters with forward slash characters. The Clojure function str calls the .toString method for x when it is given the single object x. The methods used for canonisation and relativisation can be found in java.nio.file.Path.
Code:

(defn get-resolved-path
  [root-path in-path]
  (let [path (Paths/get in-path (into-array [""]))
        server-path (Paths/get root-path (into-array [""]))
        server-dir (.getParent server-path)
        mis-dir (.resolve server-dir "Missions")]
    (string/replace (->> path (.relativize mis-dir) .normalize str) "\\" "/")))

Now that the Label text has been set, the logic is exactly the same for both routes.

This is the same global state atom update logic as with the server chooser, triggered by an InvalidationListener attached to the Label object:
Code:

(defn single-path-select
  []
  (let [{:keys [single-path-lbl]} @state/controls
        single-path (ui/get-text single-path-lbl)]
    (if (= single-path "...")
      (reset! state/mission-path nil)
      (reset! state/mission-path single-path))))

To load the mission, we click the Load/Unload button, which calls the following function:
Code:

(defn load-unload-command
  "### load-unload-command
  This is a zero argument function which unloads the currently loaded mission if
  it is loaded."
  []
  (if @state/loaded
    (server/unload-mission)
    (when (= @state/mode "single")
      (ui/toggle-prog-ind @state/controls true)
      (server/load-mission @state/mission-path))))

When there is a mission loaded, we write "mission DESTROY" to the socket. We then enquire as to the mission state for the parser to pick up the new state (because the mission DESTROY command doesn't return any output to the console):
Code:

(defn unload-mission
  "### unload-mission
  This is a zero argument function which sends the command to the server console
  which unloads the current mission. Because the unload command doesn't return
  any output on completion, we also request the mission state so that the state
  parsers can register the change in mission status."
  []
  (write-socket "mission DESTROY")
  (get-mission-state))

If the mission isn't loaded, then we write "mission LOAD <mission path>":
Code:

(defn load-mission
  "### load-mission
  This is a one argument function which sends the command to the server console
  which loads a mission using the path described by the argument."
  [path-to-mission]
  (write-socket (str "mission LOAD " path-to-mission)))

Finally, the write-socket function which outputs to the java.net.Socket output stream:
Code:

(defn write-socket
  "### write-socket
  This is a single argument function that simply calls the println method of the
  object that is stored in the socket-out atom using the argument that we
  provide.
  This atom should contain the instance of the PrintWriter object that is
  instantiated when we successfully connect to the server."
  [text]
  (.println ^PrintWriter @socket-out text))

Please note: I have also tried the following for the print command to match the server line endings:

Code:

(.print @socket-out (str text "\\n"))
(.flush @socket-out)

I even tried "\\n\\r\\n" as I noticed this in the server output quite frequently!

Output stream definition here:
Code:

(reset! socket-out (PrintWriter.
                                          (BufferedWriter.
                                            (OutputStreamWriter.
                                              (.getOutputStream ^Socket @socket)
                                              (Charset/forName "UTF-8")))
                                          true))

I have tried a couple of different values for the character set for the OutputStreamWriter, including ISO-8859-1 and leaving it blank (which should be UTF-16).

Hope this is a decent enough outline of what goes on (I'm not cagey about the code as I intend to open the repo to all once the basic feature set is complete).

One of the methods that I used to try and detect any differences in the path was to set a comparator function on the single-choose-command function using clojure.data/diff, which compared the text content of the single mission path TextField to the return value of the get-resolved-path function.

I loaded the mission using the TextField, loaded a different mission using the chooser (to trigger the bug), then loaded the original mission from the TextField using the FileChooser. In every instance it indicated that the value in the TextField (which worked every time) was the same as that returned by the FileChooser (which didn't), i.e. it returned (nil nil "Net/dogfight/DCG/dcgmission.mis").

The_WOZ, I will give your suggestion a try once I get home, thanks!

TheGrunch 02-17-2014 08:28 PM

The_WOZ, output was as follows:
Code:

% env WINEPREFIX=/home/david/Servers/il2-4.12/ strace -eopen wineconsole --backend=curses /home/david/Servers/il2-4.12/drive_d/il2server/il2server.exe
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib64/libtinfo.so.5", O_RDONLY)  = 3
open("/lib64/libdl.so.2", O_RDONLY)    = 3
open("/lib64/libc.so.6", O_RDONLY)      = 3
open("/dev/tty", O_RDWR|O_NONBLOCK)    = 3
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
open("/proc/meminfo", O_RDONLY)        = 3
open("/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) = 3
open("/usr/bin/wineconsole", O_RDONLY)  = 3
--- SIGCHLD (Child exited) @ 0 (0) ---
[ Process PID=761 runs in 32 bit mode. ]
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/usr/lib/libwine.so.1", O_RDONLY) = 3
open("/lib/libpthread.so.0", O_RDONLY)  = 3
open("/lib/libc.so.6", O_RDONLY)        = 3
open("/lib/libdl.so.2", O_RDONLY)      = 3
open("/usr/bin/wine", O_RDONLY)        = 3
open("/lib/ld-linux.so.2", O_RDONLY)    = 3
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/usr/lib/libwine.so.1", O_RDONLY) = 3
open("/lib/libpthread.so.0", O_RDONLY)  = 3
open("/lib/libc.so.6", O_RDONLY)        = 3
open("/lib/libdl.so.2", O_RDONLY)      = 3
open("/usr/lib/wine/ntdll.dll.so", O_RDONLY) = 3
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib/libm.so.6", O_RDONLY)        = 3
open(".", O_RDONLY|O_LARGEFILE)        = 3
open("/etc/nsswitch.conf", O_RDONLY)    = 4
open("/etc/ld.so.cache", O_RDONLY)      = 4
open("/lib/libnss_files.so.2", O_RDONLY) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
--- SIGCHLD (Child exited) @ 0 (0) ---
open("/proc/cpuinfo", O_RDONLY|O_LARGEFILE) = 6
open("/usr/lib/wine/kernel32.dll.so", O_RDONLY) = 6
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 6
open("/proc/ide", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/proc/scsi/scsi", O_RDONLY|O_LARGEFILE) = 6
open("/home/david/Servers/il2-4.12/dosdevices/z:/home/david", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 9
open("/usr/lib/gconv/gconv-modules.cache", O_RDONLY) = 9
open(".", O_RDONLY|O_LARGEFILE)        = 13
open(".", O_RDONLY|O_LARGEFILE)        = 13
open(".", O_RDONLY|O_LARGEFILE)        = 13
open("/usr/lib/wine/wineconsole.exe.so", O_RDONLY) = 9
open("/home/david/Servers/il2-4.12/dosdevices/c:/windows/syswow64", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 9
open("/usr/lib/wine/advapi32.dll.so", O_RDONLY) = 9
--- SIGCHLD (Child exited) @ 0 (0) ---
open("/etc/ld.so.cache", O_RDONLY)      = 9
open("/lib/libncurses.so.5", O_RDONLY)  = 9
open("/lib/libtinfo.so.5", O_RDONLY)    = 9
open("/usr/share/terminfo/x/xterm", O_RDONLY|O_LARGEFILE) = 9
open("/proc/meminfo", O_RDONLY)        = 9
open("/usr/share/terminfo/x/xterm", O_RDONLY|O_LARGEFILE) = 10

It doesn't look immediately enlightening to me, but maybe there is another system call that is likely to have some useful info?

Pfeil 02-17-2014 10:03 PM

Seems I can't be of much help I'm afraid. While I get the basic gist of what you're doing, Java isn't my cup of tea, shall we say.

Something that did occur to me: Have you tried running the server from a windows machine? Perhaps Wine is somehow "translating" one way or the other, and getting it wrong the first time.

When you compared packets in Wireshark, did you compare the first and second packet sent using the file selection dialog, or the difference(lack thereof) between textbox and dialog?

TheGrunch 02-17-2014 10:43 PM

Hi Pfeil,
I tried both, and it seems I can't find any difference in either output. :confused:

I haven't tried running the server from a Windows machine and it's quite possible that this is the culprit. However, I would still want to solve the issue as it's my main platform for running the server personally. :grin: Signs are pointing against this as my original implementation in Java worked fine with the same server using much the same methods (please excuse the horrors which follow as it was pretty much the first GUI application I ever wrote and it's rather crufty about accessing the UI and the config in the application logic):

Server interaction:
Code:

public class Command {

    @Inject
    Connection connection;

    @Inject
    public void sendCommand(String line) {
        connection.getOutput().println(line);
        connection.getOutput().flush();
        if (connection.getOutput().checkError()) {
            System.out.println("Not sent.");
        }
    }

    public void loadMission(String mission) {
        sendCommand("mission LOAD " + mission);
    }

    public void endMission() {
        sendCommand("mission DESTROY");
    }

    public void askMission() {
        sendCommand("mission");
    }

}

Connection:
Code:

public void connect() {

        try {
            socket = new Socket(Config.getIpAddress(), Integer.decode(Config.getPort()));
            output = new PrintWriter(socket.getOutputStream(), true);
            input = new BufferedReader(new InputStreamReader(socket.getInputStream(), Charset.forName("UTF-8")));
            setConnected(true);
            if (socket.isConnected()) {
                System.out.println("Connected to server " + Config.getIpAddress() + " on port " + Config.getPort());
            }
        } catch (IOException e) {
            setConnected(false);
            System.out.println("Failed to connect to socket.");
            e.printStackTrace();
        }

    }

Choosers:
Code:

public void serverPathButtonAction() {
        String serverPath;
        File file = serverChooser.showOpenDialog(new Stage());
        if (file != null) {
            serverPath = file.toString();
            Config.setServerPath(serverPath);
            serverPathLabel.setText(serverPath);
            missionPathButton.setDisable(false);
        } else {
            serverPathLabel.setText("<no server .exe selected>");
            missionPathButton.setDisable(true);
        }

    }

    public void missionPathButtonAction() {
        String missionPath;
        File file = missionChooser.showOpenDialog(new Stage());
        if (file != null) {
            missionPath = file.toString();
            Config.setMissionPath(missionPath);
            missionPathLabel.setText(missionPath);
        } else {
            missionPathLabel.setText("<no .mis file selected>");
        }

    }

Path resolution:
Code:

public String resolveMissionPath() {
        Path serverPath;
        Path missionPath;
        Path missionsRoot;
        Path missionLoadPath;
        String missionLoadString;

        serverPath = Paths.get(Config.getServerPath());
        missionPath = Paths.get(Config.getMissionPath());

        missionsRoot = serverPath.getParent().resolve("Missions");
        missionLoadPath = missionsRoot.relativize(missionPath).normalize();
        missionLoadString = missionLoadPath.toString().replace("\\", "/");
        return missionLoadString;
    }

Load/unload command:
Code:

public void startStopButtonAction() {
        if (Mission.getMissionRunning()) {
            command.endMission();
            command.askMission();
        } else {
            if (Config.getRemoteMode()) {
                command.loadMission(Config.getRemotePath());
            } else {
                command.loadMission(mainConfigPresenter.resolveMissionPath());
            }
        }
    }

Things that are definitely different:
  • The PrintWriter only wraps the OutputStream (i.e. it is not buffered as in my current implementation).
  • I use the .toString() method on the File rather than .getCanonicalPath.
  • I used the CheckError() method previously. Maybe there is actually an error state on the socket?

Just tried using all of these with no luck. :(

The_WOZ 02-18-2014 03:21 AM

Quote:

Originally Posted by TheGrunch (Post 514957)
The_WOZ, output was as follows:
Code:

% env WINEPREFIX=/home/david/Servers/il2-4.12/ strace -eopen wineconsole --backend=curses /home/david/Servers/il2-4.12/drive_d/il2server/il2server.exe
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib64/libtinfo.so.5", O_RDONLY)  = 3
open("/lib64/libdl.so.2", O_RDONLY)    = 3
open("/lib64/libc.so.6", O_RDONLY)      = 3
open("/dev/tty", O_RDWR|O_NONBLOCK)    = 3
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
open("/proc/meminfo", O_RDONLY)        = 3
open("/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) = 3
open("/usr/bin/wineconsole", O_RDONLY)  = 3
--- SIGCHLD (Child exited) @ 0 (0) ---
[ Process PID=761 runs in 32 bit mode. ]
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/usr/lib/libwine.so.1", O_RDONLY) = 3
open("/lib/libpthread.so.0", O_RDONLY)  = 3
open("/lib/libc.so.6", O_RDONLY)        = 3
open("/lib/libdl.so.2", O_RDONLY)      = 3
open("/usr/bin/wine", O_RDONLY)        = 3
open("/lib/ld-linux.so.2", O_RDONLY)    = 3
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/usr/lib/libwine.so.1", O_RDONLY) = 3
open("/lib/libpthread.so.0", O_RDONLY)  = 3
open("/lib/libc.so.6", O_RDONLY)        = 3
open("/lib/libdl.so.2", O_RDONLY)      = 3
open("/usr/lib/wine/ntdll.dll.so", O_RDONLY) = 3
open("/etc/ld.so.cache", O_RDONLY)      = 3
open("/lib/libm.so.6", O_RDONLY)        = 3
open(".", O_RDONLY|O_LARGEFILE)        = 3
open("/etc/nsswitch.conf", O_RDONLY)    = 4
open("/etc/ld.so.cache", O_RDONLY)      = 4
open("/lib/libnss_files.so.2", O_RDONLY) = 4
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
--- SIGCHLD (Child exited) @ 0 (0) ---
open("/proc/cpuinfo", O_RDONLY|O_LARGEFILE) = 6
open("/usr/lib/wine/kernel32.dll.so", O_RDONLY) = 6
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 6
open("/proc/ide", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/proc/scsi/scsi", O_RDONLY|O_LARGEFILE) = 6
open("/home/david/Servers/il2-4.12/dosdevices/z:/home/david", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 9
open("/usr/lib/gconv/gconv-modules.cache", O_RDONLY) = 9
open(".", O_RDONLY|O_LARGEFILE)        = 13
open(".", O_RDONLY|O_LARGEFILE)        = 13
open(".", O_RDONLY|O_LARGEFILE)        = 13
open("/usr/lib/wine/wineconsole.exe.so", O_RDONLY) = 9
open("/home/david/Servers/il2-4.12/dosdevices/c:/windows/syswow64", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 9
open("/usr/lib/wine/advapi32.dll.so", O_RDONLY) = 9
--- SIGCHLD (Child exited) @ 0 (0) ---
open("/etc/ld.so.cache", O_RDONLY)      = 9
open("/lib/libncurses.so.5", O_RDONLY)  = 9
open("/lib/libtinfo.so.5", O_RDONLY)    = 9
open("/usr/share/terminfo/x/xterm", O_RDONLY|O_LARGEFILE) = 9
open("/proc/meminfo", O_RDONLY)        = 9
open("/usr/share/terminfo/x/xterm", O_RDONLY|O_LARGEFILE) = 10

It doesn't look immediately enlightening to me, but maybe there is another system call that is likely to have some useful info?

It doesnt look like it from the dump but, did you test loading missions when you tried strace?

Try loading missions both ways, then a second time from the file chooser. Then look in the output from strace, if the open path for the .mis file differs.

TheGrunch 02-18-2014 06:10 AM

The_WOZ, tried loading using both methods before, text field first and then chooser; perhaps wineconsole is interfering with the output. Is there a way I could send the output to a file?

Sent from my ST23i using Tapatalk

The_WOZ 02-18-2014 03:45 PM

Ah, it must be because the server is a child process to the wine executable, so strace is only logging the system calls from wine itself, and not the server.

Try this:

strace -o <logfilename> -e file -f <program>

the -o option outputs the log to a file
-e file now logs all file related operations, not just calls to file open.
-f logs system calls from child processes.


All times are GMT. The time now is 10:51 AM.

Powered by vBulletin® Version 3.8.4
Copyright ©2000 - 2025, Jelsoft Enterprises Ltd.
Copyright © 2007 Fulqrum Publishing. All rights reserved.