File: gmBackendListener.py

package info (click to toggle)
gnumed-server 22.15-1
  • links: PTS, VCS
  • area: main
  • in suites: bullseye
  • size: 46,556 kB
  • sloc: sql: 1,217,005; python: 15,469; sh: 1,553; makefile: 20
file content (427 lines) | stat: -rw-r--r-- 12,777 bytes parent folder | download | duplicates (2)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
__doc__ = """GNUmed database backend listener.

This module implements threaded listening for asynchronuous
notifications from the database backend.
"""
#=====================================================================
__author__ = "H. Herb <hherb@gnumed.net>, K.Hilbert <karsten.hilbert@gmx.net>"
__license__ = "GPL v2 or later"

import sys
import time
import threading
import select
import logging


if __name__ == '__main__':
	sys.path.insert(0, '../../')
from Gnumed.pycommon import gmDispatcher
from Gnumed.pycommon import gmBorg


_log = logging.getLogger('gm.db')


signals2listen4 = [
	'db_maintenance_warning',		# warns of impending maintenance and asks for disconnect
	'db_maintenance_disconnect',	# announces a forced disconnect and disconnects
	'gm_table_mod'					# sent for any (registered) table modification, payload contains details
]

#=====================================================================
class gmBackendListener(gmBorg.cBorg):

	def __init__(self, conn=None, poll_interval=3):

		try:
			self.already_inited
			return

		except AttributeError:
			pass

		self.debug = False
		self.__notifications_received = 0
		self.__messages_sent = 0

		_log.info('starting backend notifications listener thread')

		# the listener thread will regularly try to acquire
		# this lock, when it succeeds it will quit
		self._quit_lock = threading.Lock()
		# take the lock now so it cannot be taken by the worker
		# thread until it is released in shutdown()
		if not self._quit_lock.acquire(0):
			_log.error('cannot acquire thread-quit lock, aborting')
			raise EnvironmentError("cannot acquire thread-quit lock")

		self._conn = conn
		self.backend_pid = self._conn.get_backend_pid()
		_log.debug('notification listener connection has backend PID [%s]', self.backend_pid)
		self._conn.set_isolation_level(0)		# autocommit mode = psycopg2.extensions.ISOLATION_LEVEL_AUTOCOMMIT
		self._cursor = self._conn.cursor()
		try:
			self._conn_fd = self._conn.fileno()
		except AttributeError:
			self._conn_fd = self._cursor.fileno()
		self._conn_lock = threading.Lock()		# lock for access to connection object

		self.__register_interests()

		# check for messages every 'poll_interval' seconds
		self._poll_interval = poll_interval
		self._listener_thread = None
		self.__start_thread()

		self.already_inited = True

	#-------------------------------
	# public API
	#-------------------------------
	def shutdown(self):
		_log.debug('received %s notifications', self.__notifications_received)
		_log.debug('sent %s messages', self.__messages_sent)

		if self._listener_thread is None:
			self.__shutdown_connection()
			return

		_log.info('stopping backend notifications listener thread')
		self._quit_lock.release()
		try:
			# give the worker thread time to terminate
			self._listener_thread.join(self._poll_interval+2.0)
			try:
				if self._listener_thread.isAlive():
					_log.error('listener thread still alive after join()')
					_log.debug('active threads: %s' % threading.enumerate())
			except Exception:
				pass
		except Exception:
			print(sys.exc_info())

		self._listener_thread = None

		try:
			self.__unregister_unspecific_notifications()
		except Exception:
			_log.exception('unable to unregister unspecific notifications')

		self.__shutdown_connection()

		return
	#-------------------------------
	# event handlers
	#-------------------------------
	# internal helpers
	#-------------------------------
	def __register_interests(self):
		# determine unspecific notifications
		self.unspecific_notifications = signals2listen4
		_log.info('configured unspecific notifications:')
		_log.info('%s' % self.unspecific_notifications)
		gmDispatcher.known_signals.extend(self.unspecific_notifications)

		# listen to unspecific notifications
		self.__register_unspecific_notifications()

	#-------------------------------
	def __register_unspecific_notifications(self):
		for sig in self.unspecific_notifications:
			_log.info('starting to listen for [%s]' % sig)
			cmd = 'LISTEN "%s"' % sig
			self._conn_lock.acquire(1)
			try:
				self._cursor.execute(cmd)
			finally:
				self._conn_lock.release()

	#-------------------------------
	def __unregister_unspecific_notifications(self):
		for sig in self.unspecific_notifications:
			_log.info('stopping to listen for [%s]' % sig)
			cmd = 'UNLISTEN "%s"' % sig
			self._conn_lock.acquire(1)
			try:
				self._cursor.execute(cmd)
			finally:
				self._conn_lock.release()

	#-------------------------------
	def __shutdown_connection(self):
		_log.debug('shutting down connection with backend PID [%s]', self.backend_pid)
		self._conn_lock.acquire(1)
		try:
			self._conn.rollback()
		except Exception:
			pass
		finally:
			self._conn_lock.release()

	#-------------------------------
	def __start_thread(self):
		if self._conn is None:
			raise ValueError("no connection to backend available, useless to start thread")

		self._listener_thread = threading.Thread (
			target = self._process_notifications,
			name = self.__class__.__name__,
			daemon = True
		)
		_log.info('starting listener thread')
		self._listener_thread.start()

	#-------------------------------
	# the actual thread code
	#-------------------------------
	def _process_notifications(self):

		# loop until quitting
		_have_quit_lock = None
		while not _have_quit_lock:
			# quitting ?
			if self._quit_lock.acquire(0):
				break

			# wait at most self._poll_interval for new data
			self._conn_lock.acquire(1)
			try:
				ready_input_sockets = select.select([self._conn_fd], [], [], self._poll_interval)[0]
			finally:
				self._conn_lock.release()
			# any input available ?
			if len(ready_input_sockets) == 0:
				# no, select.select() timed out
				# give others a chance to grab the conn lock (eg listen/unlisten)
				time.sleep(0.3)
				continue
			# data available, wait for it to fully arrive
			self._conn_lock.acquire(1)
			try:
				self._conn.poll()
			finally:
				self._conn_lock.release()
			# any notifications ?
			while len(self._conn.notifies) > 0:
				# if self._quit_lock can be acquired we may be in
				# __del__ in which case gmDispatcher is not
				# guaranteed to exist anymore
				if self._quit_lock.acquire(0):
					_have_quit_lock = 1
					break

				self._conn_lock.acquire(1)
				try:
					notification = self._conn.notifies.pop()
				finally:
					self._conn_lock.release()
				self.__notifications_received += 1
				if self.debug:
					print(notification)
				_log.debug('#%s: %s (first param is PID of sending backend)', self.__notifications_received, notification)
				# decode payload
				payload = notification.payload.split('::')
				operation = None
				table = None
				pk_column_name = None
				pk_of_row = None
				pk_identity = None
				for item in payload:
					if item.startswith('operation='):
						operation = item.split('=')[1]
					if item.startswith('table='):
						table = item.split('=')[1]
					if item.startswith('PK name='):
						pk_column_name = item.split('=')[1]
					if item.startswith('row PK='):
						pk_of_row = int(item.split('=')[1])
					if item.startswith('person PK='):
						try:
							pk_identity = int(item.split('=')[1])
						except ValueError:
							_log.exception('error in change notification trigger')
							pk_identity = -1
				# try sending intra-client signals:
				# 1) generic signal
				self.__messages_sent += 1
				try:
					results = gmDispatcher.send (
						signal = notification.channel,
						originated_in_database = True,
						listener_pid = self.backend_pid,
						sending_backend_pid = notification.pid,
						pk_identity = pk_identity,
						operation = operation,
						table = table,
						pk_column_name = pk_column_name,
						pk_of_row = pk_of_row,
						message_index = self.__messages_sent,
						notification_index = self.__notifications_received
					)
				except Exception:
					print("problem routing notification [%s] from backend [%s] to intra-client dispatcher" % (notification.channel, notification.pid))
					print(sys.exc_info())
				# 2) dynamically emulated old style table specific signals
				if table is not None:
					self.__messages_sent += 1
					signal = '%s_mod_db' % table
					_log.debug('emulating old-style table specific signal [%s]', signal)
					try:
						results = gmDispatcher.send (
							signal = signal,
							originated_in_database = True,
							listener_pid = self.backend_pid,
							sending_backend_pid = notification.pid,
							pk_identity = pk_identity,
							operation = operation,
							table = table,
							pk_column_name = pk_column_name,
							pk_of_row = pk_of_row,
							message_index = self.__messages_sent,
							notification_index = self.__notifications_received
						)
					except Exception:
						print("problem routing notification [%s] from backend [%s] to intra-client dispatcher" % (signal, notification.pid))
						print(sys.exc_info())

				# there *may* be more pending notifications but
				# we don't care when quitting
				if self._quit_lock.acquire(0):
					_have_quit_lock = 1
					break

		# exit thread activity
		return

#=====================================================================
# main
#=====================================================================
if __name__ == "__main__":

	if len(sys.argv) < 2:
		sys.exit()

	if sys.argv[1] not in ['test', 'monitor']:
		sys.exit()


	notifies = 0

	from Gnumed.pycommon import gmPG2, gmI18N
	from Gnumed.business import gmPerson, gmPersonSearch

	gmI18N.activate_locale()
	gmI18N.install_domain(domain='gnumed')
	#-------------------------------
	def run_test():

		#-------------------------------
		def dummy(n):
			return float(n)*n/float(1+n)
		#-------------------------------
		def OnPatientModified():
			global notifies
			notifies += 1
			sys.stdout.flush()
			print("\nBackend says: patient data has been modified (%s. notification)" % notifies)
		#-------------------------------
		try:
			n = int(sys.argv[2])
		except Exception:
			print("You can set the number of iterations\nwith the second command line argument")
			n = 100000

		# try loop without backend listener
		print("Looping", n, "times through dummy function")
		i = 0
		t1 = time.time()
		while i < n:
			r = dummy(i)
			i += 1
		t2 = time.time()
		t_nothreads = t2-t1
		print("Without backend thread, it took", t_nothreads, "seconds")

		listener = gmBackendListener(conn = gmPG2.get_raw_connection())

		# now try with listener to measure impact
		print("Now in a new shell connect psql to the")
		print("database <gnumed_v9> on localhost, return")
		print("here and hit <enter> to continue.")
		input('hit <enter> when done starting psql')
		print("You now have about 30 seconds to go")
		print("to the psql shell and type")
		print(" notify patient_changed<enter>")
		print("several times.")
		print("This should trigger our backend listening callback.")
		print("You can also try to stop the demo with Ctrl-C !")

		listener.register_callback('patient_changed', OnPatientModified)

		try:
			counter = 0
			while counter < 20:
				counter += 1
				time.sleep(1)
				sys.stdout.flush()
				print('.')
			print("Looping",n,"times through dummy function")
			i = 0
			t1 = time.time()
			while i < n:
				r = dummy(i)
				i += 1
			t2 = time.time()
			t_threaded = t2-t1
			print("With backend thread, it took", t_threaded, "seconds")
			print("Difference:", t_threaded-t_nothreads)
		except KeyboardInterrupt:
			print("cancelled by user")

		listener.shutdown()
		listener.unregister_callback('patient_changed', OnPatientModified)
	#-------------------------------
	def run_monitor():

		print("starting up backend notifications monitor")

		def monitoring_callback(*args, **kwargs):
			try:
				kwargs['originated_in_database']
				print('==> got notification from database "%s":' % kwargs['signal'])
			except KeyError:
				print('==> received signal from client: "%s"' % kwargs['signal'])
			del kwargs['signal']
			for key in kwargs:
				print('    [%s]: %s' % (key, kwargs[key]))

		gmDispatcher.connect(receiver = monitoring_callback)

		listener = gmBackendListener(conn = gmPG2.get_raw_connection())
		print("listening for the following notifications:")
		print("1) unspecific:")
		for sig in listener.unspecific_notifications:
			print('   - %s' % sig)

		while True:
			pat = gmPersonSearch.ask_for_patient()
			if pat is None:
				break
			print("found patient", pat)
			gmPerson.set_active_patient(patient=pat)
			print("now waiting for notifications, hit <ENTER> to select another patient")
			input()

		print("cleanup")
		listener.shutdown()

		print("shutting down backend notifications monitor")

	#-------------------------------
	if sys.argv[1] == 'monitor':
		run_monitor()
	else:
		run_test()

#=====================================================================