Possibly irregular session abortions by ListRandomizer

[jobrachem]

Quoting @ctreffe (#205):

I am convinced that the Randomizer still does not correctly manage randomization slots. While investigating the above problem in my experiment, I came across irregularities in the randomization. Before describing the problem itself, I will outline the general parameters of my current online experiment:

I am using a ListRandomizer.balanced() to assing two experimental conditions with 80 sessions in each condition. Hence, my experiment should remain open for new participants until I have acquired 160 finished datasets (inclusive set to False). In the experimental dataset, I am able to differentiate different types of unfinished sessions by the amount of stored data and some specific settings. I am calling the randomizer from my experiment's setup hook. Before initiating the randomization, I adjust the _exp_sessiontimeout, which is the only thing happening prior to the randomization. Hence, I can differentiate states in which a session either starts regularly, or is aborted early. Specifically, there are two relevant types of sessions:

1. I have a relatively small amount of sessions (50 in 1000), for which a dataset exists, in which the _exp_sessiontimeout remains at its default value (86400 seconds). These sessions have been saved once before running the code in the setup hook, otherwise we should see the changes I made to _exp_sessiontimeout reflected in the saved dataset. In these datasets, some basic information is missing (e.g., client data and the starting time), while some critical initial information is present (e.g., save_time). These sessions have not received an experimental condition from the randomizer, at least there is no condition saved in the dataset.
2. I have a large number of datasets with assigned experimental conditions and all the initial information, but with no user input whatsoever. These datasets seem to originate from participants closing the experiment directly on the landing page, never clicking on any button in the navigation. These datasets are saved at a later stage in the startup process, after finishing the experimental setup hook, since both my changes to the _exp_sessiontimeout setting and assigned experimental conditions are reflected in the dataset.

I assume, that the first type of dataset results from the randomizer aborting the session, but somehow this is not accurately reflected in the dataset (calling abort() should set the aborted flag to true, maybe create a log entry, and it should save a reason for the abortion of the session. None of this is happening). Moreover, the logged error message shown above can be traced to this type of session data (but not all of these sessions have an associated error message in the log). There are no other sessions in my experimental data that indicate a regular call to abort() by the randomizer. Also, these 50 sessions are not evenly distributed, but start to occur more often when the majority of randomization slots are already closed. Hence, I am convinced this type of session in the experimental data set reflects an irregular abortion by the randomizer. Interestingly, I am running a Matchmaker behind the randomizer, also in the session hook. When the MatchMaker aborts the experiment due to no available matching slots, the experiment is aborted normally, specifically, the aborted state is set to true and a reason for the abortion is saved in the dataset. Also, a log entry is created. Since both the randomizer and the match maker are run in the experimental hook, I think the problem is a specific randomizer problem.

In summary, one problem seems to be that the randomizer does not work as expected when aborting the experiment due to no available randomization slots. Maybe there is an exception that is not handled, yet? This could explain why we never see regular session abortions performed by the randomizer.

[jobrachem]

It would be helpful for debugging I think, if you would add log statements to the setup hook. That way we can determine the exact last line that is executed before abortion of the session.

I think of something like this:

@exp.setup
def setup(exp):
    exp.log.info("Entering hook. Next: Set timeout")
    exp.session_timeout = 100
    exp.log.info("Timeout has been set. Next: Initialize Randomizer")
    rd = al.ListRandomizer(...)

[jobrachem]

See #208