JSON operations much slower

[XertroV]

Unknown cause, but saving and loading json from disk seems to take a lot longer now. Suspected to be related to the latest game update, but not sure.

Confirmed it's affecting more than just me.

[codecat]

Can you specifiy what exactly is slower? Json::Parse, Json::FromFile, or is it about interacting with the data inside of the already parsed structures?

[XertroV]

I believe it is Write more than anything. I did think reading was slower too but that might have just been yield bug.

Will try some quick benchmarks

[codecat]

Ok. I have changed the implementation of Json::Write to hopefully be significantly faster for next updates.

[XertroV]

Is it possible that the sleep/yield bug was causing json issues?

Saving the openplanet json file seems a lot faster than in my dev app (it does add a field before re-exporting).

Over 10 iterations reading the OpenplanetNext.json file took 29.7 ms / iter, and writing it to a string took 273.4 ms / iter. ToFile was basically the same at 275.8 ms / iter.

Over 1000 iters, instancing a SimpleJson obj took 7.36 ms / iter, writing to string was 1.52 ms / iter, parsing was 0.888 ms / iter

The SimpleJson obj was as defined below.

void RunJsonBenchmarks() {
    Bench(FromFileOpenplanetJson, "FromFileOpenplanetJson", 10, true);
    Bench(WriteOpenplanetJson, "WriteOpenplanetJson", 10, true);
    Bench(ToFileOpenplanetJson, "ToFileOpenplanetJson", 10, true);
    Bench(InstanceSimpleJsonObj1k, "InstanceSimpleJsonObj1k", 1000);
    Bench(WriteSimpleJsonObj1k, "WriteSimpleJsonObj1k", 1000);
    Bench(ParseSimpleJsonObj1k, "ParseSimpleJsonObj1k", 1000);
}

void Bench(CoroutineFunc@ f, string name, int count, bool yield_between = false) {
    uint start = Time::Now;
    uint duration = 0.;
    for (int i = 0; i < count; i++) {
        f();
        if (yield_between) {
            duration += Time::Now - start;
            sleep(0);
            start = Time::Now;
        }
    }
    uint end = Time::Now;
    uint ms = end - start + duration;
    trace(name + " took " + (float(ms) / float(count)) + "ms per iteration");
}

Json::Value@ OpenplanetJson;

void FromFileOpenplanetJson() {
    @OpenplanetJson = Json::FromFile(IO::FromDataFolder("OpenplanetNext.json"));
}

void WriteOpenplanetJson() {
    Json::Write(OpenplanetJson);
}

void ToFileOpenplanetJson() {
    Json::ToFile(IO::FromDataFolder("OpenplanetNext.json.tmp"), OpenplanetJson);
}

Json::Value@ SimpleJson;

void InstanceSimpleJsonObj1k() {
    @SimpleJson = Json::Object();
    for (int i = 0; i < 100; i++) {
        SimpleJson["key" + i] = Json::Array();
        for (int j = 0; j < 100; j++) {
            SimpleJson["key" + i].Add(j);
        }
    }
}

string simpleJsonStr;

void WriteSimpleJsonObj1k() {
    simpleJsonStr = Json::Write(SimpleJson);
}

void ParseSimpleJsonObj1k() {
    Json::Parse(simpleJsonStr);
}

[XertroV]

update: fixed

oh i forgot to exclude the yields in the openplanet json tests

[codecat]

Parsing the documentation json file in my Openplanet (debug) takes ~60ms, whereas in Go (debug) it takes ~40ms.

On release builds, this reduces to ~40ms and ~20ms respectively.

I don't think this is a particularly bad benchmark. Sure we could be faster, but not by much.

Angelscript test code:

void Main() {
    Json::FromFile(IO::FromDataFolder("Developer_OpenplanetDev.json"));
}

Go test code:

func main() {
    start := time.Now()

    fh, _ := os.Open(`C:\Users\Nimble\OpenplanetDev\Developer_OpenplanetDev.json`)
    var data map[string]interface{}
    json.NewDecoder(fh).Decode(&data)

    end := time.Now()

    log.Printf("Time to parse: %v", end.Sub(start))
}

I have not tested json writing yet.

[codecat]

Okay, so Json::ToFile was extremely slow in this case because of a lot of unnecessary memory allocations (piggybacking off of Json::Write for code simplicity). I have removed all the unnecessary allocations and (on a debug build) writing the json file that we are reading is now ~80ms.

Test code:

void Main() {
    auto start = Time::Now;
    auto js = Json::FromFile(IO::FromDataFolder("Developer_OpenplanetDev.json"));
    auto end = Time::Now;
    print("Parse duration: " + (end - start));

    start = Time::Now;
    Json::ToFile(IO::FromDataFolder("Developer_OpenplanetDev.test.json"), js);
    end = Time::Now;
    print("Write duration: " + (end - start));
}

This will still be slow when using Json::Write because of the overhead of allocating memory for the returned string, but I will be adjusting the allocation strategy in strings to make these cases generally faster as well.

[codecat]

Json::Write will now be just as fast as the updated Json::ToFile:

void Main()
{
    auto start = Time::Now;
    auto js = Json::FromFile(IO::FromDataFolder("OpenplanetNext.json"));
    auto end = Time::Now;
    print("Parse duration: " + (end - start));

    start = Time::Now;
    Json::ToFile(IO::FromDataFolder("OpenplanetNext.test.json"), js);
    end = Time::Now;
    print("Write file duration: " + (end - start));

    start = Time::Now;
    Json::Write(js);
    end = Time::Now;
    print("Write duration: " + (end - start));
}

[XertroV]

Nice