OF23_IOPerformance_Analysis_2 - wyldckat/wyldckat.github.io GitHub Wiki
Reason for this wiki page: Continuing investigation that was started in OF23_IOPerformance_Analysis.
Machine specs:
- Intel i7 950
- 24GB, 6 memory modules, DDR3 1333MHz
- 2TB hard-drive
Using the tutorial "incompressible/simpleFoam/motorBike" from OF 2.3.1, changed to ascii and using 12 precision. Commented out the "functions" entry and changed write interval to 400, out of 200. This means that no writing is done. This case runs in parallel.
Final iteration in "log.simpleFoam":
- ascii
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.000431304361578, Final residual = 2.27618756867e-05, No Iterations 4
smoothSolver: Solving for Uy, Initial residual = 0.00874223801908, Final residual = 0.000467566294739, No Iterations 4
smoothSolver: Solving for Uz, Initial residual = 0.0084499403756, Final residual = 0.000436839612344, No Iterations 4
GAMG: Solving for p, Initial residual = 0.0266260346477, Final residual = 0.000123153298017, No Iterations 4
time step continuity errors : sum local = 1.92494322754e-05, global = -4.36617429749e-07, cumulative = 6.65334468505e-05
smoothSolver: Solving for omega, Initial residual = 0.000107829894269, Final residual = 7.94785746941e-06, No Iterations 3
smoothSolver: Solving for k, Initial residual = 0.00190980225557, Final residual = 0.000162442425872, No Iterations 3
ExecutionTime = 167.39 s ClockTime = 168 s
- binary
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 166.24 s ClockTime = 166 s
Conclusion: Inconclusive... 1-2 seconds is within the margin of instabilities.
Since no writing didn't seem to affect the timing, then tried using the same ascii mesh, using write interval of 10 for a 200 iteration run.
rm -rf processor*/[1-9]* && rm log.simpleFoam
./Allrun && tail -n 20 log.simpleFoam
- ascii precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 184.65 s ClockTime = 186 s
- binary precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 167.26 s ClockTime = 168 s
- binary precision 6
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514, Final residual = 0.0210799, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065, Final residual = 0.0244799, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.356762, Final residual = 0.0148041, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187082, Final residual = 1.75198e-06, No Iterations 4
time step continuity errors : sum local = 0.74584, global = 0.158677, cumulative = 0.41774
smoothSolver: Solving for omega, Initial residual = 0.0380602, Final residual = 0.00327296, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125941, Final residual = 0.0047415, No Iterations 3
ExecutionTime = 166.03 s ClockTime = 166 s
- ascii precision 6
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514, Final residual = 0.0210799, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065, Final residual = 0.0244799, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.356762, Final residual = 0.0148041, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187082, Final residual = 1.75198e-06, No Iterations 4
time step continuity errors : sum local = 0.74584, global = 0.158677, cumulative = 0.41774
smoothSolver: Solving for omega, Initial residual = 0.0380602, Final residual = 0.00327296, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125941, Final residual = 0.0047415, No Iterations 3
ExecutionTime = 180.21 s ClockTime = 180 s
- ascii precision 8
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.30151442, Final residual = 0.021079943, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.32906501, Final residual = 0.024479933, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676211, Final residual = 0.014804064, No Iterations 3
GAMG: Solving for p, Initial residual = 0.00018708156, Final residual = 1.7519807e-06, No Iterations 4
time step continuity errors : sum local = 0.74584007, global = 0.15867702, cumulative = 0.41773992
smoothSolver: Solving for omega, Initial residual = 0.038060195, Final residual = 0.0032729588, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.12594072, Final residual = 0.0047414959, No Iterations 3
ExecutionTime = 181.67 s ClockTime = 182 s
- ascii precision 10
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.3015144183, Final residual = 0.021079943, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.3290650104, Final residual = 0.02447993331, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.3567621053, Final residual = 0.01480406372, No Iterations 3
GAMG: Solving for p, Initial residual = 0.0001870815618, Final residual = 1.75198073e-06, No Iterations 4
time step continuity errors : sum local = 0.7458400663, global = 0.1586770171, cumulative = 0.4177399195
smoothSolver: Solving for omega, Initial residual = 0.03806019528, Final residual = 0.003272958838, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.1259407246, Final residual = 0.004741495913, No Iterations 3
ExecutionTime = 181.84 s ClockTime = 182 s
- ascii precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 184.22 s ClockTime = 184 s
- binary precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 165.65 s ClockTime = 166 s
- binary precision 6
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514, Final residual = 0.0210799, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065, Final residual = 0.0244799, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.356762, Final residual = 0.0148041, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187082, Final residual = 1.75198e-06, No Iterations 4
time step continuity errors : sum local = 0.74584, global = 0.158677, cumulative = 0.41774
smoothSolver: Solving for omega, Initial residual = 0.0380602, Final residual = 0.00327296, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125941, Final residual = 0.0047415, No Iterations 3
ExecutionTime = 166.12 s ClockTime = 166 s
- ascii precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 183.61 s ClockTime = 184 s
- ascii precision 16
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.3015144183228362, Final residual = 0.02107994300044505, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.3290650103709417, Final residual = 0.02447993331266299, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.3567621052702303, Final residual = 0.0148040637248642, No Iterations 3
GAMG: Solving for p, Initial residual = 0.0001870815617507656, Final residual = 1.75198072970208e-06, No Iterations 4
time step continuity errors : sum local = 0.7458400662836818, global = 0.1586770170516915, cumulative = 0.4177399194796151
smoothSolver: Solving for omega, Initial residual = 0.03806019527960224, Final residual = 0.003272958837910294, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.1259407245553401, Final residual = 0.004741495912903257, No Iterations 3
ExecutionTime = 186.19 s ClockTime = 186 s
Conclusion:
- Results are more consistent, when compared to OF23_IOPerformance_Analysis. Clearly the other machine has stability issues, as reported at the end of that page.
- Clearly there is a large gap between ~166s in binary vs ~184s in ascii. This will be analysed in more detail in the following steps.
du -csh processor*
- ascii 16 used 1.6GB
- binary used 692MB
- Keep in mind that both have the mesh in ascii format.
Using the same strategy as in the second approach, but this time the write interval is set to 400, so that it never writes the solution fields to disk.
rm -rf processor*/[1-9]* && rm log.simpleFoam
time ./Allrun && tail -n 20 log.simpleFoam
- ascii precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 167 s ClockTime = 167 s
- binary precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 167.64 s ClockTime = 168 s
- binary precision 12 - with "solverPerformance 0" in "$WM_PROJECT_DIR/etc/controlDict", i.e. minimal output to log file
Time = 200
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
ExecutionTime = 166.64 s ClockTime = 167 s
- ascii precision 12 - with "solverPerformance 0" in "$WM_PROJECT_DIR/etc/controlDict", i.e. minimal output to log file
Time = 200
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
ExecutionTime = 167.98 s ClockTime = 169 s
- binary precision 12 - with "solverPerformance 0" in "$WM_PROJECT_DIR/etc/controlDict", i.e. minimal output to log file, and with the option "runTimeModifiable false;"
Time = 200
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
ExecutionTime = 164.8 s ClockTime = 165 s
Conclusion:
- runTimeModifiable seems to have a very small effect on performance.
- Showing and storing the solver performance does not see to affect performance.
- So far, the problem does seem to have to do with ascii vs binary storage in files.
Using the same strategy as in the second approach, but this time we have symbolic links that preemptively point to "/dev/null" for each time snapshot.
rm -rf processor*/[1-9]* && rm log.simpleFoam
for a in processor*; do cd $a; cp -r 0 10; cd 10; rm -rf include; for b in *; do rm $b; ln -s /dev/null $b; done; cd ..; for b in $(seq 20 10 200); do cp -r 10 $b; done; cd ..; done
time ./Allrun && tail -n 20 log.simpleFoam
Note: Don't forget to change the startFrom to startTime.
- binary precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 165.84 s ClockTime = 166 s
- ascii precision 12
Time = 200
smoothSolver: Solving for Ux, Initial residual = 0.301514418323, Final residual = 0.0210799430004, No Iterations 3
smoothSolver: Solving for Uy, Initial residual = 0.329065010371, Final residual = 0.0244799333127, No Iterations 3
smoothSolver: Solving for Uz, Initial residual = 0.35676210527, Final residual = 0.0148040637249, No Iterations 3
GAMG: Solving for p, Initial residual = 0.000187081561751, Final residual = 1.7519807297e-06, No Iterations 4
time step continuity errors : sum local = 0.745840066284, global = 0.158677017052, cumulative = 0.41773991948
smoothSolver: Solving for omega, Initial residual = 0.0380601952796, Final residual = 0.00327295883791, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.125940724555, Final residual = 0.0047414959129, No Iterations 3
ExecutionTime = 182.43 s ClockTime = 183 s
Conclusion:
- The delay seems to be related to how the data is coded to ascii.
- It's necessary to do some basic C++ tests to assess if this is generic or OpenFOAM related only.
Using the same strategy as in the second approach, but written every iteration and to stop at 50 iterations, since it will use up a lot of disk space.
rm -rf processor*/[1-9]* && rm log.simpleFoam
time ./Allrun && tail -n 20 log.simpleFoam
Note: Don't forget to change the startFrom to startTime.
- ascii precision 12
Time = 50
smoothSolver: Solving for Ux, Initial residual = 0.00460969055496, Final residual = 0.000265880736179, No Iterations 4
smoothSolver: Solving for Uy, Initial residual = 0.0625085845313, Final residual = 0.00338121875257, No Iterations 4
smoothSolver: Solving for Uz, Initial residual = 0.0709078537671, Final residual = 0.00674492777744, No Iterations 3
GAMG: Solving for p, Initial residual = 0.201599409438, Final residual = 0.00191658365529, No Iterations 4
time step continuity errors : sum local = 0.000384682643061, global = 5.11082646854e-05, cumulative = 0.00279829505137
smoothSolver: Solving for omega, Initial residual = 0.00127385565228, Final residual = 9.34182147613e-05, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.0231239390257, Final residual = 0.00208249296403, No Iterations 2
ExecutionTime = 86.62 s ClockTime = 88 s
- binary precision 12
Time = 50
smoothSolver: Solving for Ux, Initial residual = 0.00460969055496, Final residual = 0.000265880736179, No Iterations 4
smoothSolver: Solving for Uy, Initial residual = 0.0625085845313, Final residual = 0.00338121875257, No Iterations 4
smoothSolver: Solving for Uz, Initial residual = 0.0709078537671, Final residual = 0.00674492777744, No Iterations 3
GAMG: Solving for p, Initial residual = 0.201599409438, Final residual = 0.00191658365529, No Iterations 4
time step continuity errors : sum local = 0.000384682643061, global = 5.11082646854e-05, cumulative = 0.00279829505137
smoothSolver: Solving for omega, Initial residual = 0.00127385565228, Final residual = 9.34182147613e-05, No Iterations 2
smoothSolver: Solving for k, Initial residual = 0.0231239390257, Final residual = 0.00208249296403, No Iterations 2
ExecutionTime = 42.7 s ClockTime = 44 s
As for disk space taken up by each mode:
du -csh processor*
- ascii 12 used 3.1 GB
- binary used 1.6 GB
- Keep in mind that both have the mesh in ascii format.
- ascii took roughly twice as long to run than binary... Definitely need to test raw C++ file storage.
Testing performance of raw C++ code. Reference: http://www.cplusplus.com/doc/tutorial/files/
Source code files:
- ascii.c
// writing on a text file
#include <iostream>
#include <fstream>
using namespace std;
int main () {
ofstream myfile ("test.ascii");
const int maxi=5000000;
if (myfile.is_open())
{
for(int i=0; i<maxi; i++)
{
double test = double(i)*2.12348521325;
myfile << test;
}
myfile.close();
}
else cout << "Unable to open file";
return 0;
}
- ascii_sprintf_f.c
// writing on a text file
#include <iostream>
#include <fstream>
using namespace std;
int main () {
ofstream myfile ("test.ascii_sprintf_f");
const int maxi=5000000;
char buffer[200];
if (myfile.is_open())
{
for(int i=0; i<maxi; i++)
{
double test = double(i)*2.12348521325;
int sz = sprintf(buffer, "%f", test);
myfile.write(buffer,sz);
}
myfile.close();
}
else cout << "Unable to open file";
return 0;
}
- ascii_sprintf_g.c
// writing on a text file
#include <iostream>
#include <fstream>
using namespace std;
int main () {
ofstream myfile ("test.ascii_sprintf_g");
const int maxi=5000000;
char buffer[200];
if (myfile.is_open())
{
for(int i=0; i<maxi; i++)
{
double test = double(i)*2.12348521325;
int sz = sprintf(buffer, "%g", test);
myfile.write(buffer,sz);
}
myfile.close();
}
else cout << "Unable to open file";
return 0;
}
- binary.c
// writing on a text file
#include <iostream>
#include <fstream>
using namespace std;
int main () {
ofstream myfile ("test.binary", ios::binary);
const int maxi=5000000;
if (myfile.is_open())
{
for(int i=0; i<maxi; i++)
{
double test = double(i)*2.12348521325;
myfile.write((char *)&test,sizeof(double));
}
myfile.close();
}
else cout << "Unable to open file";
return 0;
}
Commands to use these two:
g++ ascii.c -o ascii
g++ ascii_sprintf_f.c -o ascii_sprintf_f
g++ ascii_sprintf_g.c -o ascii_sprintf_g
g++ binary.c -o binary
time ./ascii
time ./ascii_sprintf_f
time ./ascii_sprintf_g
time ./binary
Resulting timings:
time ./ascii
real 0m3.102s
user 0m3.047s
sys 0m0.054s
time ./ascii_sprintf_f
real 0m3.911s
user 0m3.839s
sys 0m0.070s
time ./ascii_sprintf_g
real 0m2.609s
user 0m2.558s
sys 0m0.051s
time ./binary
real 0m0.142s
user 0m0.098s
sys 0m0.043s
File sizes:
ll test.*
-rw-rw-r--. 1 ofuser ofuser 52180111 Dec 30 19:14 test.ascii
-rw-rw-r--. 1 ofuser ofuser 69767509 Dec 30 19:14 test.ascii_sprintf_f
-rw-rw-r--. 1 ofuser ofuser 52180111 Dec 30 19:14 test.ascii_sprintf_g
-rw-rw-r--. 1 ofuser ofuser 40000000 Dec 30 19:14 test.binary
Conclusion: Should have done this test first. Clearly writing in binary format is the most efficient way to do this.
Bonus test - what about compression? Here's a quick test:
$ for a in test.*; do echo $a; time gzip $a; done
test.ascii
real 0m1.062s
user 0m1.041s
sys 0m0.020s
test.ascii_sprintf_f
real 0m6.208s
user 0m6.169s
sys 0m0.037s
test.ascii_sprintf_g
real 0m1.061s
user 0m1.044s
sys 0m0.016s
test.binary
real 0m2.689s
user 0m2.650s
sys 0m0.037s
ll test.*
-rw-rw-r--. 1 ofuser ofuser 2452385 Dec 30 19:14 test.ascii.gz
-rw-rw-r--. 1 ofuser ofuser 29881711 Dec 30 19:14 test.ascii_sprintf_f.gz
-rw-rw-r--. 1 ofuser ofuser 2452395 Dec 30 19:14 test.ascii_sprintf_g.gz
-rw-rw-r--. 1 ofuser ofuser 27629527 Dec 30 19:14 test.binary.gz
Summary of these findings have been shared here: Binary gives significant performance advantage (Mesh & Solve) - post #16
In addition, the missing interpretation of all of this is also on that thread, in post #18.