IPC callback not returning most recent response time; discrepancies in outputs

Hello,

In the following code snippet I hope to convey through the comments and accompanying output table the strange behavior observed with certain IPC callbacks. Case1 and Case2 work fine and return normal results as shown in the output, but I’m having trouble explaining the behavior of the cases after (please see comments).

 

I hope someone could answer the questions Q1, Q2, and Q3 in lines 21, 26, and 33 respectively, as well as provide overall clarification to the behaviors observed here. 

 

 

 

/IPC Time Discrepancy Illustration h: hopen 5000 /case1, works /I denote t0 as the time before sending a message, recording and tf as the final time when getting back a response. t0:.z.n; (neg h)({(neg .z.w)“tf:.z.n”};) times: enlist initialTimefinalTimeDifferenceFunctionCase!(t0;tf;tf-t0;None;1) /Making table to record results /case2, works /Same as case1 but wrapped into a function ping2: {t0::.z.n; (neg x)({(neg .z.w)"tf:.z.n"};)} ping2 h times upsert (t0;tf;tf-t0;ping2;2) /case3, tf < t0 /By changing case2’s function only so that it returns tf, tf records earlier than t0 ping3:{t0::.z.n; (neg x)({(neg .z.w)“tf:.z.n”};); times upsert (t0;tf;tf-t0;ping3;3)} ping3 h /I call this line a few times to illustrate the following point in the output- /Notice that the finalTime is always very close to the initialTime of the last run, no matter how far apart in time the runs are. /Q1: Why does viewing t0 and tf from within a function seem to cause tf &lt; t0? /case4: However, when examining t0 and tf outside of ping3, it works fine: times upsert (t0;tf;tf-t0;OutsidePing3;4) /Q2: No modifications have been made to t0 &amp; tf; how is it that now t0 &lt; tf as normal? /case5: Another strange behavior, running case 2 all at once, again tf &lt; t0! ping2 h; times upsert (t0;tf;tf-t0;ping2Concurrent;5) /There seems to be a common pattern here that running the ping command and then viewing the output variables in the same execution produces an impossible result that the final time is earlier than the initial time /But that if the commands are manually run one after another, t0 < tf as normal. /Q3: Is it possible to perform the concurrent execuion in a single function call with normal results?

 

 

Output table from above code. I have highlighted the point made in line 20. 

 

Hi Michael,

I think what’s happening here is that in the functions you are effectively recycling the tf value from previous call.  When executing the function, the callback updates tf after the upsert as the q proc is processing the function, step-by-step tf can get updated between steps.

Adding in a sync chaser (x"" below) ensures the work is done on the remote process and tf is updated before the upsert.

 

 

/IPC Time Discrepancy Illustration h: hopen 5001 /case1, works /I denote t0 as the time before sending a message, recording and tf as the final time when getting back a response. t0:.z.n; (neg h)({(neg .z.w)“tf:.z.n”};); times: enlist initialTimefinalTimeDifferenceFunctionCase!(t0;tf;tf-t0;None;1); /Making table to record results /case2, works /Same as case1 but wrapped into a function ping2: {t0::.z.n; (neg x)({(neg .z.w)"tf:.z.n"};);x"";}; ping2 h; times upsert (t0;tf;tf-t0;ping2;2) /case3, tf < t0 /By changing case2’s function only so that it returns tf, tf records earlier than t0 ping3:{t0::.z.n; (neg x)({(neg .z.w)“tf:.z.n”};);x""; times upsert (t0;tf;tf-t0;ping3;3)} ; ping3 h /I call this line a few times to illustrate the following point in the output- /Notice that the finalTime is always very close to the initialTime of the last run, no matter how far apart in time the runs are. /Q1: Why does viewing t0 and tf from within a function seem to cause tf &lt; t0? /case4: However, when examining t0 and tf outside of ping3, it works fine: times upsert (t0;tf;tf-t0;OutsidePing3;4) /Q2: No modifications have been made to t0 &amp; tf; how is it that now t0 &lt; tf as normal? /case5: Another strange behavior, running case 2 all at once, again tf &lt; t0! ping2 h; times upsert (t0;tf;tf-t0;ping2Concurrent;5)

 

Patrick

 

Hello Patrick,

 

Thank you for your response. Adding the chaser does seem to update tf before the upsert. 

Could you go into what’s causing ping3 without the chaser to reference the penultimate tf? Is it that the asynchronous-ness of the callback causes the upsert to run while the callback is running, and so if the upsert is faster, then the callback will not finish in time, and tf will not get updated? (So we see the penultimate value) 

Is this also why case2 works? That is, in the time it takes me to manually execute the callback and upsert, the async callback finishes before the upsert, so the upsert reports the correct tf? 

May I ask, what the chaser does? I’m confused as to how sending an empty synchronous message after the callback causes ping3 to reference the latest tf.

 

Thank you so much,

Michael

Hi Michael,

ping3 will run the upsert with the ‘old’ tf value before the callback updates tf, as it’s within the same function call.  The callback will execute post function call.
ping 2 is command by command, so the callback can execute before the upsert, updating tf to the latest time.  The function call, forces the execution sequence, .i.e the upsert will always run before the callback as it’s within the func.
The chaser will block on the handle (as it’s sync), ensuring that the remote end has received and processed the async messages, therefore updating tf before the upsert.

The below are very helpful docs:

https://code.kx.com/q/wp/ipc/

https://code.kx.com/q/basics/ipc/#block-queue-flush 

Patrick