Misleading INFO message.

[drtconway]

When running as an agent, bpipe produces output like the following:

bpipe.agent.JMSAgent    [1]     INFO    |3:30:49 Blocked waiting for 222000 for current commands to complete ... 
bpipe.agent.JMSAgent    [1]     INFO    |3:30:59 Blocked waiting for 224000 for current commands to complete ... 
bpipe.agent.JMSAgent    [1]     INFO    |3:31:09 Blocked waiting for 226000 for current commands to complete ... 
bpipe.agent.JMSAgent    [1]     INFO    |3:31:19 Blocked waiting for 228000 for current commands to complete ... 
bpipe.agent.JMSAgent    [1]     INFO    |3:31:29 Blocked waiting for 230000 for current commands to complete ... 

with a new message ever 10s or so.

I believe the code at:

https://github.com/ssadedin/bpipe/blob/12fd28001769c3596b2ee8167e8ea8693cf33f2c/src/main/groovy/bpipe/agent/JMSAgent.groovy#L421C26-L421C30

should be doing a wait for waitMS not 2000.

[ssadedin]

I took a look at this but I think the code is operating as intended.

The waitMs is just used to count how long it has waited. It checks every 2 seconds whether the concurrency allows it to start, but that should remain as a fixed 2 seconds.

That said there are a couple of bugs to fix I think.

• waitMs should be incremented outside the if statement
• n is not incremented at all, so it actually emits a log statement every loop iteration

I'll fix these so the logging is not so frequent (by intent, should be logging once every 8 seconds).

[ssadedin]

See fc6a330

[ssadedin]

See 38ada1c

realised n is a actually incremented via prefix op in the if statement

[drtconway]

Can I suggest adding "ms" to the end of the wait time in the message?

Actually converting it to seconds might be human friendly too.

Having the "ms" or "s" would make it a bit clearer to read - when I first saw the message I misread it as that number of jobs being waited on!

[ssadedin]

That's a good idea, will patch that in. Thanks!