Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tomes that finish fast fail to respond when another task is blocking IO #754

Open
hulto opened this issue Apr 19, 2024 · 1 comment
Open
Labels
bug Something isn't working imix

Comments

@hulto
Copy link
Collaborator

hulto commented Apr 19, 2024

Describe the bug
When a tome is performing an IO blocking operation like: sleeping, or making a network connection it can prevent other tomes from sending output back to tavern.
This only seems to affect tomes that finish quickly (likely within the time between claim_task and report.)
"fast" Tomes that have had this issue:

  • Get env
  • Shell execute cmd: id
  • Process list match: *

/realm/implants/imix/src/agent.rs:78

    /*
     * Callback once using the configured client to claim new tasks and report available output.
     */
    pub async fn callback(&mut self) -> Result<()> {
        let transport = GRPC::new(self.cfg.callback_uri.clone(), self.cfg.proxy_uri.clone())?;
        self.claim_tasks(transport.clone()).await?;
        self.report(transport.clone()).await?;

        Ok(())
    }

To Reproduce

  1. Create an IO blocking tome:
def main():
    time.sleep(999999)

main()
  1. Import it to tavern - I temporarily replaced realm/tavern/tomes/example/main.eldritch with the above and the start tavern.
  2. Run a "fast" tome to make sure it works
  3. Run the IO blocking tome
image
  1. Run a "fast" tome again and see how it stays in the Queued state
image
  1. Run a slow tome and see that it finishes as expceted
image

Expected behavior
Tomes should never interfere with each other. Even if a tome is infinitely blocking other tomes should be able to complete.

@hulto hulto added bug Something isn't working imix labels Apr 19, 2024
@hulto
Copy link
Collaborator Author

hulto commented Apr 19, 2024

Logs

Success case (slow execution)

 2024-04-19T00:29:41.178Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:29:46.283Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:29:51.385Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:29:56.490Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:30:01.492Z INFO  imix::agent             > 1 tasks claimed
 2024-04-19T00:30:01.492Z INFO  imix::agent             > spawned task execution for id=42949672965
 2024-04-19T00:30:01.493Z INFO  eldritch::runtime::eval > evaluating tome (task_id=42949672965)
 2024-04-19T00:30:01.693Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:30:01.696Z INFO  imix::task              > message success (task_id=42949672965,msg=ReportAggOutput)
 2024-04-19T00:30:06.502Z INFO  eldritch::runtime::eval > tome evaluation successful (task_id=42949672965)
 2024-04-19T00:30:06.798Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:30:06.801Z INFO  imix::task              > message success (task_id=42949672965,msg=ReportAggOutput)
 2024-04-19T00:30:11.901Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:30:17.006Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
 2024-04-19T00:30:22.109Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)

Failure case (fast execution)

 2024-04-19T00:30:47.631Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:30:52.736Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:30:57.839Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:31:02.842Z INFO  imix::agent             > 1 tasks claimed
2024-04-19T00:31:02.842Z INFO  imix::agent             > spawned task execution for id=42949672966
2024-04-19T00:31:02.842Z INFO  eldritch::runtime::eval > evaluating tome (task_id=42949672966)
2024-04-19T00:31:02.846Z INFO  eldritch::runtime::eval > tome evaluation successful (task_id=42949672966)
2024-04-19T00:31:02.942Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:31:08.048Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:31:13.150Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:31:18.254Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)
2024-04-19T00:31:23.357Z INFO  imix::agent             > callback complete (duration=0s, sleep=5s)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working imix
Projects
None yet
Development

No branches or pull requests

1 participant