Diagnostics and Grounding

This page is about what to do when something goes wrong: a rule is refused, a program has no answer sets when you expected some, or grounding takes forever. It covers the errors ASPAlchemy gives you, how clingo’s own messages are mapped back to your Python, how to look at the ASP you wrote and the ground program clingo actually solves, and how to find out where a large grounding comes from.

Errors that teach

ASPAlchemy checks each statement as you write it, so errors show up on the line of Python that caused them, rather than at solve time somewhere else entirely. Every error message tries to say what went wrong and what you probably meant instead. Refusals are reserved for things clingo would reject or that are almost certainly mistakes, so a valid program shouldn’t run into them. The full list of what is refused, and why, is in What We Don’t Support.

Here’s an example. We build a small scheduling program, and then try to state a “fact” that still contains a variable:

from aspalchemy import ASPProgram, Choice, Field, Predicate, Variable

class Task(Predicate, show=False):
    name: Field[str]

class Slot(Predicate, show=False):
    hour: Field[int]

class Scheduled(Predicate):
    task: Field[str]
    hour: Field[int]

program = ASPProgram()
program.fact(Task(name="brew"), Task(name="bottle"))
program.fact(*(Slot(hour=h) for h in (9, 10, 11)))
T, H = Variable("T"), Variable("H")
program.when(Task(name=T)).derive(
    Choice(Scheduled(task=T, hour=H), condition=Slot(hour=H)) == 1
)

A fact with a variable in it isn’t a fact, and the error says so:

>>> program.fact(Scheduled(task=T, hour=9))
Traceback (most recent call last):
  ...
ValueError: fact() requires grounded predicates, but scheduled(T, 9) contains variable(s) T. Use when(*conditions).derive(...) to derive predicates.

It names the atom, the variable, and what you probably wanted to write instead.

Source locations

Every statement remembers the line of Python that created it. You can turn this off with ASPProgram(source_locations=False), but there’s rarely a reason to. These locations show up in three places: the error for an unfinished when() (below), in render(annotate=True), and in the “generated by” notes on clingo’s messages.

The unfinished when() error is the one you’re most likely to see first. Every when() has to be finished with exactly one of derive, choose, require, forbid or penalize. If one is left unfinished when you render, the error tells you where it was started, which is where the fix goes:

scratch = ASPProgram()
pending = scratch.when(Slot(hour=H))  # started, never finished

>>> scratch.render()
Traceback (most recent call last):
  ...
ValueError: Segment 'Rules' has incomplete when() statements: when(slot(H)) opened at ... Complete each with .derive/.choose/.require/.forbid/.penalize.

The ... there is the file and line of the when(). You can still finish pending afterwards, and the next render will work.

For framework authors

By default, the recorded line is the first line of code outside ASPAlchemy. That’s right for a script, but if you’re building a framework on top of ASPAlchemy, every location would point at your framework’s code instead of your users’ code. There are a few tools to fix that:

  • register_skip_package("myfw") tells ASPAlchemy to skip over a package, so locations point at whoever called it. If a package contains some code you do want locations to point at, register just the modules to skip ("myfw.core", "myfw.solvers.base"). Registration lasts for the whole process, so only register names you own.
  • @attribute_to_caller marks a single function that writes rules on behalf of its caller, so the location is the line that called it. It only covers that function itself, not lambdas or comprehensions inside it (registering the module covers those).
  • location_override(loc) attributes everything created inside a with block to a location you supply. This is for when the right location isn’t on the stack at all, such as a framework that writes rules in a final pass, long after the user wrote the code responsible. capture_location() gives you a location to save for later: the first line on the stack that isn’t skipped.

This is how aspuzzle, a grid-puzzle framework built on ASPAlchemy, points its diagnostics at each puzzle’s definition instead of at the framework.

Seeing the ASP

program.render() gives you the program text: the clingo you would have written by hand. The tutorial covers it in full. For the scheduling program above, it is:

>>> print(program.render())
% Generated by aspalchemy ...
task("brew").
task("bottle").
slot(9).
slot(10).
slot(11).
{ scheduled(T, H) : slot(H) } = 1 :- task(T).

#show.
#show scheduled/2.

render(annotate=True) adds a % file:line comment to the end of each statement, naming the line of Python that wrote it. The line numbers of the output don’t change, so if clingo (or any other tool) complains about line N of the plain render, line N of the annotated render tells you where it came from.

Here’s the same program, built with location_override so that the comments name a fixed file rather than this page. In your program, they’ll name your own files and lines:

from aspalchemy import SourceLocation, location_override

brewery = ASPProgram()
with location_override(SourceLocation("brewery.py", 14)):
    brewery.fact(Task(name="brew"), Task(name="bottle"))
with location_override(SourceLocation("brewery.py", 15)):
    brewery.fact(*(Slot(hour=h) for h in (9, 10, 11)))
with location_override(SourceLocation("brewery.py", 19)):
    brewery.when(Task(name=T)).derive(
        Choice(Scheduled(task=T, hour=H), condition=Slot(hour=H)) == 1
    )

>>> print(brewery.render(annotate=True))
% Generated by aspalchemy ...
task("brew").  % brewery.py:14
task("bottle").  % brewery.py:14
slot(9).  % brewery.py:15
slot(10).  % brewery.py:15
slot(11).  % brewery.py:15
{ scheduled(T, H) : slot(H) } = 1 :- task(T).  % brewery.py:19

#show.
#show scheduled/2.

Annotation is off by default because the comments change whenever you edit your Python, even when the program doesn’t. If you check renders into version control or compare them in tests, leave them unannotated.

Organizing output

A few verbs help make the rendered program easier to read. comment(text) writes a % comment, blank_line() writes a blank line, and section(title) does both. They make no difference to solving, and they pay for themselves the first time you read through a 200-line render.

For bigger programs, you can split the output into segments. Every program starts with a default segment, which is where the program-level verbs write. add_segment("name") adds a named segment and returns it; it has all the same statement verbs, and you can get it back later with program["name"]. Once a program has named segments, each one is rendered under a banner:

Wall = Predicate.define("wall", ["at"], show=False)

house = ASPProgram()
board_seg = house.add_segment("board")
board_seg.section("Board geometry")
board_seg.fact(Wall(at=1))

house.comment("program-level verbs write to the default segment")
house.fact(Wall(at=2))

>>> print(house.render())
% Generated by aspalchemy ...

% ===== board =====

% Board geometry
wall(1).


% ===== Rules =====

% program-level verbs write to the default segment
wall(2).

#show.

>>> house["board"] is board_seg  # get the segment back by name
True

Segments are rendered in the order they were added, no matter when statements were written to them. That means you can set up a “definitions” segment first, and fill it in as you go.

Segment groups

If you want to write a program out as several files, you can put segments in groups: add_segment("data", group="input"). Then render(group="input") renders just the segments in that group, as a file of its own. program.group_of("data") tells you which group a segment is in, and program.set_group("data", "rules") moves it to another group (None moves it back to the default group).

Segments that don’t name a group go in the default group, which is called "base" unless you pass ASPProgram(default_group=...). The default group’s file also carries every #const and the #show block. Every segment is in exactly one group, so rendering every group gives you the whole program back, split across files.

>>> jobs = ASPProgram()
>>> data = jobs.add_segment("data", group="input")
>>> plan = jobs.add_segment("plan", group="rules")
>>> data.fact(Task(name="brew"), Task(name="bottle"))
>>> plan.when(Task(name=T)).derive(Scheduled(task=T, hour=9))
>>> jobs.groups
('base', 'input', 'rules')
>>> print(jobs.render(group="input"))
% Generated by aspalchemy ...
% Render group: input

% ===== data =====

task("brew").
task("bottle").
>>> print(jobs.render(group="base"))   # here just the #show block, plus any #const
% Generated by aspalchemy ...
% Render group: base

#show.
#show scheduled/2.

A word of caution: each group’s file can be read by clingo on its own, but it won’t necessarily solve correctly on its own. Whenever you give group files to clingo, always include the default group’s file, because that’s where the constants are. Clingo doesn’t complain about a constant it has never seen defined; it just treats it as a symbol, and your program quietly gives different answers (H > cutoff with cutoff undefined is always false).

Groups only affect rendering. ground() and solve() always use the whole program.

Seeing the ground program

render() shows you the program you wrote, but clingo solves the ground program: every rule written out for every combination of values that fits. When grounding does something you didn’t expect, that’s the text to look at. A GroundedProgram gives it to you in two formats:

  • ground_text() is the ground program as readable text (what gringo --text prints).
  • aspif() is exactly what the solver receives, the same as clingo --mode=gringo prints. It’s harder to read, but it’s the more accurate measure of how big a grounding really is. For example, ground_text() repeats the shared elements of a banded aggregate, so it looks twice as big as it is; aspif() doesn’t.
from aspalchemy import RangePool

class Pick(Predicate, show=False):
    n: Field[int]

class Big(Predicate):
    n: Field[int]

X = Variable("X")
pick_program = ASPProgram()
pick_program.choose(Choice(Pick(n=RangePool(1, 3))))
pick_program.when(Pick(n=X), X > 1).derive(Big(n=X))

grounded = pick_program.ground()

The program has one choice rule and one rule with a variable. ground_text() shows what they became:

>>> print(grounded.ground_text())
{pick(1)}.
{pick(2)}.
{pick(3)}.
big(2):-pick(2).
big(3):-pick(3).
#show.
#show big/1.

And aspif() shows the same program as the solver sees it, with numbered atoms:

>>> print(grounded.aspif())
asp 1 0 0 incremental
1 1 1 1 0 0
1 1 1 2 0 0
1 1 1 3 0 0
1 0 1 4 0 1 2
1 0 1 5 0 1 3
4 6 big(2) 1 4
4 6 big(3) 1 5
0

Both of these ground the program again each time you call them. If you grounded with ground(context=...), and your Python functions give different answers on different calls, the output may not match your original grounding.

Profiling grounding

When grounding is slow or huge, start with grounded.analyze_grounding(). It counts the ground atoms of each predicate, largest first, along with the lines of Python that derive them. The lines at the top are the ones to rethink.

Here’s a program with a deliberately large rule: 30 items, a rule that derives every ordered pair of them, and a symmetry constraint that will matter in the next section. (The statements use location_override so the output below doesn’t change; in your program, you’ll see your own files and lines.)

class Item(Predicate, show=False):
    n: Field[int]

class Pair(Predicate):
    a: Field[int]
    b: Field[int]

A, B = Variable("A"), Variable("B")
prof_program = ASPProgram()
with location_override(SourceLocation("puzzle.py", 12)):
    prof_program.when(X.in_(RangePool(1, 30))).derive(Item(n=X))
with location_override(SourceLocation("puzzle.py", 13)):
    prof_program.when(Item(n=A), Item(n=B)).derive(Pair(a=A, b=B))
with location_override(SourceLocation("puzzle.py", 14)):
    prof_program.forbid(Pair(a=A, b=B), Pair(a=B, b=A), A != B)

>>> report = prof_program.ground().analyze_grounding()
>>> print(report)
Grounding profile: 930 ground atoms across 2 signatures
  pair/2: 900 atoms — derived at puzzle.py:13
  item/1: 30 atoms — derived at puzzle.py:12

The top row is the 30 × 30 pairs: that’s the line to rethink. If you want the data rather than a printout, grounding_profile() returns one SignatureGrounding per predicate, with name, arity, atom_count and derived_at.

This report only counts atoms, so it can’t see a statement that does a lot of work without deriving much, and it can’t see constraints at all, because they don’t derive anything. That’s what the next section is for. (Grounding is only half of the cost of a big program; the other half is reading the models back, which is covered in A note on scale.)

Profiling by statement

analyze_statements() gives every statement its own row, constraints included, counting how many times gringo grounded it. Here’s the same program again, and this time the constraint shows up:

>>> print(prof_program.ground().analyze_statements())
Statement profile: 1800 ground instantiations across 3 statements
         900  pair(A, B) :- item(A), item(B).  — puzzle.py:13
         870  :- pair(A, B), pair(B, A), A != B.  — puzzle.py:14
          30  item(X) :- X = 1..30.  — puzzle.py:12

The constraint, which the previous report couldn’t see at all, is the second-largest row. In real programs, it’s often the largest. statement_profile() returns the same data as one StatementGrounding per statement, with statement, location and instances.

A few things to know about these counts:

  • They count every instance gringo grounds, including ones it then throws away or merges together, so they can be bigger than what you see in ground_text().
  • minimize() and maximize() statements aren’t counted.
  • Each call grounds the program again, so the same caveat about ground(context=...) applies as for ground_text().
  • Statements inside raw_asp() text are counted on a best-effort basis, line by line. A statement that spans several lines, or that shares a line with another statement, is left out, as are raw weak constraints and directives.

Profiling recursion

Recursive rules are grounded differently. Gringo grounds a group of rules that depend on each other by going around and around until nothing new is derived, and every rule in that loop is grounded again on every pass. A rule that doesn’t need to be inside the loop, but is, is a classic cause of slow grounding.

analyze_recursion() finds these loops just by looking at your program, before any grounding happens:

X, Y, Z = Variable("X"), Variable("Y"), Variable("Z")

class Edge(Predicate, show=False):
    a: Field[int]
    b: Field[int]

class Reach(Predicate):
    a: Field[int]
    b: Field[int]

tc_program = ASPProgram()
with location_override(SourceLocation("paths.py", 7)):
    tc_program.fact(Edge(a=1, b=2), Edge(a=2, b=3))
with location_override(SourceLocation("paths.py", 8)):
    tc_program.when(Edge(a=X, b=Y)).derive(Reach(a=X, b=Y))
with location_override(SourceLocation("paths.py", 9)):
    tc_program.when(Reach(a=X, b=Y), Edge(a=Y, b=Z)).derive(Reach(a=X, b=Z))

>>> print(tc_program.analyze_recursion())
Recursion profile: 1 recursive component
  reach/2
    reach(X, Z) :- reach(X, Y), edge(Y, Z).  — paths.py:9

The rule on line 8 gets the loop started, but isn’t part of it, so it isn’t listed. Only rules that use the loop’s own predicates are.

recursion_profile() returns the same data as one RecursiveComponent per loop, with signatures, statements, and unstratified. A loop is unstratified when it goes through default negation, such as p :- not q. q :- not p.: the rules are defined in terms of their own absence. Gringo can’t work those out while grounding, so the solver has to guess and check instead. That’s expensive, and usually not what you meant. A well-shaped program reads like a stack: data at the bottom, then choices, then rules on top, with each layer only negating things from the layers below it.

This analysis doesn’t run gringo, and it can’t see inside raw_asp() text.

Clingo’s messages

Some mistakes can only be caught during grounding, and clingo reports those as log messages rather than errors, at LogLevel.INFO, WARNING or ERROR. ground(), and every verb that grounds (solve, brave, cautious, optimize), takes a stop_on_log_level, and any message at or above that level raises a GroundingError. The default is INFO, the strictest setting, because some of clingo’s quietest messages are about serious problems. (There is also CRITICAL, which means “never stop”.)

The main example is division by zero. Clingo quietly drops any rule instance where the arithmetic is undefined, with just an info message, so your program silently loses rules. With ASPAlchemy’s default, that’s an error instead, and the message includes a “generated by” note pointing at the line of Python that wrote the rule. (This uses location_override again, to keep the output stable.)

from aspalchemy import GroundingError, LogLevel

class Amount(Predicate, show=False):
    n: Field[int]

class Ratio(Predicate):
    n: Field[int]

ratio_program = ASPProgram()
with location_override(SourceLocation("recipe.py", 30)):
    ratio_program.fact(Amount(n=0), Amount(n=2))
    ratio_program.when(Amount(n=X)).derive(Ratio(n=10 // X))  # 10 // 0 is undefined

The error quotes the rendered ASP, underlines the problem (Python’s // is clingo’s /), and then points at the Python:

>>> ratio_program.solve().first()
Traceback (most recent call last):
  ...
aspalchemy.exceptions.GroundingError: Grounding produced INFO level messages (stop threshold: INFO).
...
INFO: operation undefined:
  (10/X)

  at line 4, columns 7-13

  in block
   3 | amount(2).
   4 | ratio(10 / X) :- amount(X).
             ^^^^^^
  generated by recipe.py:30
...

The messages are also on the exception as e.messages, a tuple of ClingoMessage. If your code needs to check for a particular message, check these fields rather than the text. .location is the line of Python, and the other fields (severity, position in the rendered ASP, and the message text) come straight from clingo:

>>> message = None
>>> try:
...     ratio_program.solve().first()
... except GroundingError as e:
...     message = e.messages[0]
>>> assert message is not None    # the solve raised, as shown above
>>> message.severity
<LogLevel.INFO: 10>
>>> message.location
SourceLocation(filename='recipe.py', lineno=30)

The “generated by” note works for any statement, including ones inside raw_asp() text: ASPAlchemy doesn’t check raw text as you write it, but clingo’s messages about it still point back to the line that called raw_asp.

“atom does not occur in any rule head”

This is the INFO message you’ll probably run into first. If a predicate only ever appears under default negation, and nothing in the program derives it, gringo flags it, and with the default threshold, solve() raises. This happens most often with input data that happens to be empty. The program below is perfectly sensible; there just aren’t any bookings yet:

class Room(Predicate, show=False):
    number: Field[int]

class Booked(Predicate, show=False):
    room: Field[int]

class Free(Predicate):
    room: Field[int]

R = Variable("R")
free_program = ASPProgram()
free_program.fact(Room(number=101), Room(number=102))
# ...booking data would be loaded here, and today there is none
free_program.when(Room(number=R), ~Booked(room=R)).derive(Free(room=R))

>>> free_program.solve().first()
Traceback (most recent call last):
  ...
aspalchemy.exceptions.GroundingError: Grounding produced INFO level messages (stop threshold: INFO).
...
INFO: atom does not occur in any rule head:
  booked(R)
...
   4 | free(R) :- room(R), not booked(R).
                               ^^^^^^^^^
  generated by ...

Gringo has a point: an atom that nothing derives is often a typo. Here, though, it’s deliberate. The best fix is to tell clingo that the predicate is meant to have no rules, using clingo’s #defined directive in raw_asp():

>>> free_program.raw_asp("#defined booked/1.")
>>> free = free_program.solve().first()
>>> sorted(f.room for f in free.atoms(Free))  # no bookings: all free
[101, 102]

You could also give the predicate a rule somewhere, or raise the threshold. Raising the threshold works, but it lets through exactly the silent behavior the default protects you from:

>>> models = list(ratio_program.solve(stop_on_log_level=LogLevel.WARNING))
>>> len(models)  # facts and one rule: exactly one answer set
1
>>> [r.n for r in models[0].atoms(Ratio)]  # ratio(10/0) is just... gone
[5]

ratio(5) is there, but the instance for Amount(n=0) has disappeared without a trace. Only raise the threshold once you’ve read the message and decided that’s what you want.

Messages from solving, rather than grounding, never stop the search; they are collected on the result instead. See Statistics and messages.