utwente-fmt / ltsmin

The LTSmin model checking toolset
http://ltsmin.utwente.nl
BSD 3-Clause "New" or "Revised" License
53 stars 31 forks source link

pins2lts-mc : non deterministic behavior #141

Closed yanntm closed 7 years ago

yanntm commented 7 years ago

Hi,

this is related to the post in issue 109

Trying to trace the fact that an accepting cycle is not found, I get non determinisitic results with more than one thread ; The source files are on my other post.

The more threads, the more often it seems to find an accepted trace in my experiments. Running with -procs=1 is the worst, I have'nt had a run where the trace was found

I still get some variation in the trace with procs=1, [Blue] reports diffferent values for both "levels" and "transition" metrics in each run, but idk if that's normal or not.

With more procs, an accepting trace is often found, though the depth at which it is found varies greatly between runs (and sometimes it is not found), I guess it's normal in this case to have variation though since we interrupt on first accepted trace.

A trace with 2 procs below, run twice (in a row), finds an accepted run in one but not the other.

[ythierry@oxygen ltsmin (next)]$ src/pins2lts-mc/pins2lts-mc ../ITS-Tools-pnmcc/INPUTS/Railroad-PT-005/gal.so  --when --ltl 'X(<>(X([]((LTLAP15==true)))))' --procs=2
pins2lts-mc, 0.000, ** error **: Unable to open cgroup memory limit file /sys/fs/cgroup/memory/memory.limit_in_bytes: No such file or directory
pins2lts-mc, 0.000: =============================================================================
pins2lts-mc, 0.000: Runtime environment could only preallocate 125 GB while requesting 1004 GB.
pins2lts-mc, 0.000:         Configure your system limits to exploit all memory.
pins2lts-mc, 0.000: =============================================================================
pins2lts-mc( 0/ 2), 0.000: Registering PINS so language module
pins2lts-mc( 1/ 2), 0.000: Registering PINS so language module
pins2lts-mc( 0/ 2), 0.000: Loading model from ../ITS-Tools-pnmcc/INPUTS/Railroad-PT-005/gal.so
pins2lts-mc( 0/ 2), 0.000: library has no initializer
pins2lts-mc( 0/ 2), 0.000: loading model GAL
pins2lts-mc( 1/ 2), 0.000: library has no initializer
pins2lts-mc( 1/ 2), 0.000: loading model GAL
pins2lts-mc( 1/ 2), 0.000: completed loading model GAL
pins2lts-mc( 0/ 2), 0.000: completed loading model GAL
pins2lts-mc( 0/ 2), 0.000: LTL layer: formula: X(<>(X([]((LTLAP15==true)))))
pins2lts-mc( 1/ 2), 0.000: LTL layer: formula: X(<>(X([]((LTLAP15==true)))))
pins2lts-mc( 1/ 2), 0.000: "X(<>(X([]((LTLAP15==true)))))" is not a file, parsing as formula...
pins2lts-mc( 0/ 2), 0.000: "X(<>(X([]((LTLAP15==true)))))" is not a file, parsing as formula...
pins2lts-mc( 1/ 2), 0.000: Using Spin LTL semantics
pins2lts-mc( 0/ 2), 0.000: Using Spin LTL semantics
pins2lts-mc( 1/ 2), 0.000: buchi has 2 states
pins2lts-mc( 0/ 2), 0.000: buchi has 2 states
pins2lts-mc( 0/ 2), 0.001: There are 76 state labels and 1 edge labels
pins2lts-mc( 0/ 2), 0.001: State length is 55, there are 60 groups
pins2lts-mc( 0/ 2), 0.001: Running cndfs using 2 cores
pins2lts-mc( 0/ 2), 0.001: Using a tree table with 2^30 elements
pins2lts-mc( 0/ 2), 0.001: Successor permutation: dynamic
pins2lts-mc( 0/ 2), 0.001: Global bits: 2, count bits: 0, local bits: 0
pins2lts-mc( 0/ 2), 0.009: [Blue] ~480 levels ~1000 states ~4012 transitions
pins2lts-mc( 1/ 2), 0.012:  
pins2lts-mc( 1/ 2), 0.012: Accepting cycle FOUND at depth 587!
pins2lts-mc( 1/ 2), 0.012:  
pins2lts-mc( 0/ 2), 0.012:  
pins2lts-mc( 0/ 2), 0.012: Explored 1337 states 5342 transitions, fanout: 3.996
pins2lts-mc( 0/ 2), 0.012: Total exploration time 0.010 sec (0.010 sec minimum, 0.010 sec on average)
pins2lts-mc( 0/ 2), 0.012: States per second: 133700, Transitions per second: 534200
pins2lts-mc( 0/ 2), 0.012:  
pins2lts-mc( 0/ 2), 0.012: State space has 1599 states, 0 are accepting
pins2lts-mc( 0/ 2), 0.012: cndfs_1 (permutation: dynamic) stats:
pins2lts-mc( 0/ 2), 0.012: blue states: 1337 (83.61%), transitions: 0 (per worker)
pins2lts-mc( 0/ 2), 0.012: red states: 0 (0.00%), bogus: 0  (0.00%), transitions: 0, waits: 0 (0.00 sec)
pins2lts-mc( 0/ 2), 0.012: all-red states: 0 (0.00%), bogus 0 (0.00%)
pins2lts-mc( 0/ 2), 0.012:  
pins2lts-mc( 0/ 2), 0.012: Total memory used for local state coloring: 0.0MB
pins2lts-mc( 0/ 2), 0.012:  
pins2lts-mc( 0/ 2), 0.012: Queue width: 8B, total height: 1220, memory: 0.01MB
pins2lts-mc( 0/ 2), 0.012: Tree memory: 0.0MB, 22.4 B/state, compr.: 10.1%
pins2lts-mc( 0/ 2), 0.012: Tree fill ratio (roots/leafs): 0.0%/0.0%
pins2lts-mc( 0/ 2), 0.012: Stored 59 string chucks using 0MB
pins2lts-mc( 0/ 2), 0.012: Total memory used for chunk indexing: 0MB
pins2lts-mc( 0/ 2), 0.012: Est. total memory use: 0.0MB (~8192.0MB paged-in)
[ythierry@oxygen ltsmin (next)]$ src/pins2lts-mc/pins2lts-mc ../ITS-Tools-pnmcc/INPUTS/Railroad-PT-005/gal.so  --when --ltl 'X(<>(X([]((LTLAP15==true)))))' --procs=2
pins2lts-mc, 0.000, ** error **: Unable to open cgroup memory limit file /sys/fs/cgroup/memory/memory.limit_in_bytes: No such file or directory
pins2lts-mc, 0.000: =============================================================================
pins2lts-mc, 0.000: Runtime environment could only preallocate 125 GB while requesting 1004 GB.
pins2lts-mc, 0.000:         Configure your system limits to exploit all memory.
pins2lts-mc, 0.000: =============================================================================
pins2lts-mc( 0/ 2), 0.000: Registering PINS so language module
pins2lts-mc( 1/ 2), 0.000: Registering PINS so language module
pins2lts-mc( 0/ 2), 0.000: Loading model from ../ITS-Tools-pnmcc/INPUTS/Railroad-PT-005/gal.so
pins2lts-mc( 0/ 2), 0.000: library has no initializer
pins2lts-mc( 1/ 2), 0.000: library has no initializer
pins2lts-mc( 0/ 2), 0.000: loading model GAL
pins2lts-mc( 1/ 2), 0.000: loading model GAL
pins2lts-mc( 1/ 2), 0.000: completed loading model GAL
pins2lts-mc( 0/ 2), 0.000: completed loading model GAL
pins2lts-mc( 1/ 2), 0.000: LTL layer: formula: X(<>(X([]((LTLAP15==true)))))
pins2lts-mc( 0/ 2), 0.000: LTL layer: formula: X(<>(X([]((LTLAP15==true)))))
pins2lts-mc( 1/ 2), 0.000: "X(<>(X([]((LTLAP15==true)))))" is not a file, parsing as formula...
pins2lts-mc( 0/ 2), 0.000: "X(<>(X([]((LTLAP15==true)))))" is not a file, parsing as formula...
pins2lts-mc( 1/ 2), 0.000: Using Spin LTL semantics
pins2lts-mc( 0/ 2), 0.001: Using Spin LTL semantics
pins2lts-mc( 1/ 2), 0.001: buchi has 2 states
pins2lts-mc( 0/ 2), 0.001: buchi has 2 states
pins2lts-mc( 0/ 2), 0.001: There are 76 state labels and 1 edge labels
pins2lts-mc( 0/ 2), 0.001: State length is 55, there are 60 groups
pins2lts-mc( 0/ 2), 0.001: Running cndfs using 2 cores
pins2lts-mc( 0/ 2), 0.001: Using a tree table with 2^30 elements
pins2lts-mc( 0/ 2), 0.001: Successor permutation: dynamic
pins2lts-mc( 0/ 2), 0.001: Global bits: 2, count bits: 0, local bits: 0
pins2lts-mc( 0/ 2), 0.010: [Blue] ~464 levels ~1000 states ~4060 transitions
pins2lts-mc( 1/ 2), 0.015: [Blue] ~897 levels ~2000 states ~8266 transitions
pins2lts-mc( 0/ 2), 0.023:  
pins2lts-mc( 0/ 2), 0.023: Explored 3369 states 14262 transitions, fanout: 4.233
pins2lts-mc( 0/ 2), 0.023: Total exploration time 0.020 sec (0.020 sec minimum, 0.020 sec on average)
pins2lts-mc( 0/ 2), 0.023: States per second: 168450, Transitions per second: 713100
pins2lts-mc( 0/ 2), 0.023:  
pins2lts-mc( 0/ 2), 0.023: State space has 1853 states, 0 are accepting
pins2lts-mc( 0/ 2), 0.023: cndfs_1 (permutation: dynamic) stats:
pins2lts-mc( 0/ 2), 0.023: blue states: 3369 (181.81%), transitions: 0 (per worker)
pins2lts-mc( 0/ 2), 0.023: red states: 0 (0.00%), bogus: 0  (0.00%), transitions: 0, waits: 0 (0.00 sec)
pins2lts-mc( 0/ 2), 0.023: all-red states: 0 (0.00%), bogus 0 (0.00%)
pins2lts-mc( 0/ 2), 0.023:  
pins2lts-mc( 0/ 2), 0.023: Total memory used for local state coloring: 0.0MB
pins2lts-mc( 0/ 2), 0.023:  
pins2lts-mc( 0/ 2), 0.023: Queue width: 8B, total height: 2589, memory: 0.02MB
pins2lts-mc( 0/ 2), 0.023: Tree memory: 0.0MB, 21.8 B/state, compr.: 9.8%
pins2lts-mc( 0/ 2), 0.023: Tree fill ratio (roots/leafs): 0.0%/0.0%
pins2lts-mc( 0/ 2), 0.023: Stored 57 string chucks using 0MB
pins2lts-mc( 0/ 2), 0.023: Total memory used for chunk indexing: 0MB
pins2lts-mc( 0/ 2), 0.023: Est. total memory use: 0.1MB (~8192.0MB paged-in)
yanntm commented 7 years ago

I found some unitialized fields see PR, but the problem is still unsolved.

yanntm commented 7 years ago

More diagnosis traces, playing around with --strategy=, 5 runs per strat,

Out of 5 runs, how many times was a witness found ? With --procs=1 / --procs=4

bfs : 0 / 0
sbfs : 0 / 0
dfs : 0 / 0
cndfs : 0 / 4
lndfs : 5 / 5
endfs : 0 / crash file hre_malloc.c, line 147: assertion "RTgetMallocRegion() == NULL" failed
renault : 5 / 5
ufscc : 5 / 5
ndfs : 5 / 5 

renault, ufscc, ndfs, and lndfs are well behaved in these runs.

many strategies miss the counter-example (same root cause ?) There's an issue with endfs overallocating on my machine too.

cndfs behaves better with --procs=4 ; It still missed the trace in one out of 5 runs. This led to my original report of non-deterministic behavior (it's the default I believe)

bfs, sbfs, dfs, and endfs behave really bad (always miss the cex).

Maybe knowing the history of which of these strats share some root features you can debug more easily.

yanntm commented 7 years ago

Ok,

oops, mea culpa !

so the issue was due to malformed read dependency matrices apparently. Some algorithms must use this information more heavily, despite not activating POR.

I had trouble tracking the problem, since the tests for some (non deterministic) reason still passed after the change that broke my read matrices. So it wasn't obvious which commit should be incriminated. But after trying several versions of LTSmin it became obvious that the problem was on the input side (my files are broken).

In the end, --check --por was able to diagnose correctly and help me debug, I should run it in my test suite I guess/try that first when I have problems.

So, sorry for posting the issue here when the problem's on my side,

I'm closing this issue, apologies again.

alaarman commented 7 years ago

The bug reports close themselves :) The tree compression uses the dependency matrix. Was --check (alone) also able to find this incorrect dependency? It should be pretty thorough on checking only read/write matrices.

alaarman commented 7 years ago

What about report #109 ?

yanntm commented 7 years ago

yes,

--check was finding it even without --por

my post on #109 is about the same model, that regression was indeed patched by this fix of my generator code.