Обсуждение: Strange update behaviour

Hi Gentz, 

  I'm in a dire need of help, because this bug is killing me for weeks now. 

  I got a function, and that function has a simple update query in it: 

UPDATE app_devices SET device_state = p_values[1], device_updateTs = NOW(),
device_changets = CASE WHEN device_state <> p_values[1] THEN NOW() ELSE device_changets END,
device_alertstate = CASE WHEN device_state <> p_values[1] THEN 0 ELSE device_alertstate END
WHERE device_id=dev_id;

 The device_alertstate's default value is 200. update and changets are null by default. 

 And I constantly face a result when the device_state is updated, changets and updatets are populated, but the device_alertstate remains on the default 200. 

  As far as I can tell from the second round and forward it works well. 

  I am simply not able to come up with any reasons for this to happen. 

Thank you very much in advance!

Bests, 

András

ProfiVPS Support <support@profivps.hu> writes:
>    I'm in a dire need of help, because this bug is killing me for weeks 
> now.

What you showed us seems odd, but with zero context it's impossible to
tell what's really going on.  Can you provide a self-contained test case?
(And while you're at it, how about mentioning the PG version?)

            regards, tom lane

2023-06-23 00:11 időpontban Tom Lane ezt írta:

ProfiVPS Support <support@profivps.hu> writes:

   I'm in a dire need of help, because this bug is killing me for weeks
now.

What you showed us seems odd, but with zero context it's impossible to
tell what's really going on.  Can you provide a self-contained test case?
(And while you're at it, how about mentioning the PG version?)

            regards, tom lane

Hi there, 

  thank you for your reply. 

  I do agree it's odd. 

  The changets is when the new and old state differs. UpdateTs when an upadte of state happens. alertstate is to track if the state change was handled (0: unhandled state change). As Im looking for state change, this update query seemed reasonable, if there is better, I could not think of it :/

  I use a function that's called by CollectD to insert values into a table, and part of it is to update the app_devices table with the device's state. This also means data (function calls) arrive in batches, and it is even possible that the same device gets updated multiple times in a batch. It also happens in transactions that are closed every 2 seconds. 

  There is only one more task that writes device_alertstate, however, that only selects those records where device_alertstate is 0 (and record is created with 200).

  Here is what I tested: 

  - added new record to app_devices (device_state=0; device_alertstate=200; updatets/changets = null)

  - updated via the function with state =1 - the result: device_state=1; device_alertstate=200; updatets/changets = NOW()

  - kept updating with state=1, nothing changed (except the updatets ofc). 

  - updated via the function with state =0 - the result: device_state=0; device_alertstate=0; updatets/changets = NOW()

  - everything works fine from here

 Then: 

  - new record 

  - update via function with state 1 - the result: device_state=1; device_alertstate=200; updatets/changets = NOW()

  - update manually to state=0 - (device_state=0; device_alertstate=200; updatets/changets = unchanged)

  - update via function with state 1 - the result is the wanted: device_state=1; device_alertstate=0; updatets/changets = NOW()

 Then: 

  - new record

  - updated with state=0 - the result result is good, although not expected**: device_state=0; device_alertstate=0; updatets/changets = NOW()

  - everything works fine from here. 

 ** it is not expected as the default value is 0 and I sent in a 0 value. 

  For me this just does not make sense. 

  I tried to replicate this manually with a simple table and the same update query structure, but never happened, every single time all the variables got updated as expected. However, the issue I described happens _a_ _lot_ in production, but as far as I know, it happens randomly. 

  The production runs on deb11: psql (PostgreSQL) 13.11 (Debian 13.11-1.pgdg100+1)

  Same happens on deb10 and ubuntu 20.04.

  I created some dumps, removed foreign key and such stuff: https://pastebin.com/rju4eD9n

  And here is the function: https://pastebin.com/vM2MvGug  

  Calling the function like this should work: 

  SELECT collectd_insert(CURRENT_TIMESTAMP, 'DE:AD:A7:14:69:9210.123.4.12', 'ruckusphp', '', 'pstates_enabled', 'state', '{et}', '{0}', '{1}');

  The last {1} is the state value. 

  I hope everything is there to enable testing. 

Thanks again,

András

ProfiVPS Support <support@profivps.hu> writes:
>    I hope everything is there to enable testing.

Thanks for sending a test case!  But I think this is a logic bug
in your function.  There are several updates of app_devices in
that function.  Adding some "raise notice" commands to track the
logic flow, I see that the given case results in

# SELECT collectd_insert(CURRENT_TIMESTAMP,
'DE:AD:A7:14:69:9210.123.4.12', 'ruckusphp', '', 'pstates_enabled',
'state', '{et}', '{0}', '{1}');
NOTICE:  first update happening
NOTICE:  fourth update happening
 collectd_insert
-----------------

(1 row)

So it is first doing

                UPDATE app_devices SET device_state=1, device_changets=NOW(), device_updatets=NOW()
                       WHERE device_id= dev_id;

and then later doing the UPDATE you showed.  But at that point,
device_state is already 1 so neither of the device_alertstate or
device_changets updates change the column's value.  It's unobvious
that the device_changets update is a no-op because the first
UPDATE already set it to the same new value.

            regards, tom lane

Tom, 

  thank you. 

  Man, I feel stupid now. It's true: with reason :D I completely forgot about those updates and was only concentrating on the end update, because those previous updates should not even be there....

  I've been banging my head for weeks again and again on this problem, never once scrolled up... Even had a colleague to review it

Thank you very much! Im really grateful :)

Bests, 

András

2023-06-23 03:56 időpontban Tom Lane ezt írta:

ProfiVPS Support <support@profivps.hu> writes:

   I hope everything is there to enable testing.

Thanks for sending a test case!  But I think this is a logic bug
in your function.  There are several updates of app_devices in
that function.  Adding some "raise notice" commands to track the
logic flow, I see that the given case results in

# SELECT collectd_insert(CURRENT_TIMESTAMP,
'DE:AD:A7:14:69:9210.123.4.12', 'ruckusphp', '', 'pstates_enabled',
'state', '{et}', '{0}', '{1}');
NOTICE:  first update happening
NOTICE:  fourth update happening
 collectd_insert
-----------------
 
(1 row)

So it is first doing

                UPDATE app_devices SET device_state=1, device_changets=NOW(), device_updatets=NOW()
                       WHERE device_id= dev_id;

and then later doing the UPDATE you showed.  But at that point,
device_state is already 1 so neither of the device_alertstate or
device_changets updates change the column's value.  It's unobvious
that the device_changets update is a no-op because the first
UPDATE already set it to the same new value.

            regards, tom lane