flocklab_serialproxy.py 21.6 KB
Newer Older
1
2
#! /usr/bin/env python3

3
import os, sys, getopt, traceback, MySQLdb, signal, time, errno, subprocess, logging, __main__, multiprocessing, queue, threading, select, socket, io, lxml.etree
4
5
6
7
import lib.daemon as daemon
import lib.flocklab as flocklab


8
9
10
11
logger      = None
debug       = False
stopevent   = None
reloadevent = None
12
13
14
15
16
17
18
19


##############################################################################
#
# sigterm_handler
#
##############################################################################
def sigterm_handler(signum, frame):
Reto Da Forno's avatar
Reto Da Forno committed
20
21
22
23
24
25
26
27
28
29
30
31
32
33
    """If the program is terminated by sending it the signal SIGTERM 
    (e.g. by executing 'kill') or SIGINT (pressing ctrl-c), 
    this signal handler is invoked for cleanup."""
    # NOTE: logging should not be used in signal handlers: https://docs.python.org/2/library/logging.html#thread-safety
    
    global stopevent
    global reloadevent
    
    logger.debug("sigterm_handler: signal %u received" % (signum))
    # Signal all threads to stop:
    if signum == signal.SIGTERM and stopevent:
        stopevent.set()
    elif signum == signal.SIGINT and reloadevent:
        reloadevent.set()
34
35
### END sigterm_handler

Reto Da Forno's avatar
Reto Da Forno committed
36

37
38
39
40
41
42
##############################################################################
#
# listen_process
#
##############################################################################
def listen_process(port, newConnectionQueue, _stopevent):
Reto Da Forno's avatar
Reto Da Forno committed
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
    while not _stopevent.is_set():
        try:
            sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
            sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
            sock.bind(('',port))
            sock.settimeout(1)
            logger.info("Started socket %s:%d"%('',port))
            while not _stopevent.is_set():
                sock.listen(1)
                try:
                    connection, address = sock.accept()
                except socket.timeout:
                    continue
                connection.settimeout(None)
                logger.info("Connection from %s at port %d"%(str(address),port))
                address = (address[0], port)
                newConnectionQueue.put((connection, address))
            logger.info("Listen process on port %d ended." % port)
        except:
            logger.error("Listen process on port %d: Socket error %s"%(port,str(sys.exc_info()[1])))
        time.sleep(5)
64
65
### END listen_process

Reto Da Forno's avatar
Reto Da Forno committed
66

67
68
69
70
71
72
##############################################################################
#
# obs_connect_process
#
##############################################################################
def obs_connect_process(conreqQueue, condoneQueue, _stopevent):
Reto Da Forno's avatar
Reto Da Forno committed
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
    worklist = []
    while not _stopevent.is_set():
        try:
            req = conreqQueue.get(True, 1)
            worklist.append(req)
        except queue.Empty:
            pass
        for w in worklist:
            if w is None:
                worklist = []
                break
            sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
            try:
                sock.connect(w)
                logger.info("Connected to observer %s on port %d" % (w[0],w[1]))
                condoneQueue.put((sock, w))
            except ConnectionRefusedError:
Reto Da Forno's avatar
Reto Da Forno committed
90
                logger.info("Could not connect to observer %s on port %d, dropping connection." % (w[0],w[1]))
Reto Da Forno's avatar
Reto Da Forno committed
91
92
            except Exception:
                logger.info("Could not connect to observer %s on port %d: %s, %s\n%s" % (w[0], w[1], str(sys.exc_info()[0]), str(sys.exc_info()[1]), traceback.format_exc()))
Reto Da Forno's avatar
Reto Da Forno committed
93
94
            finally:
                worklist.remove(w)
95
96
### END obs_connect_process

Reto Da Forno's avatar
Reto Da Forno committed
97

98
99
100
101
102
103
##############################################################################
#
# update_configuration_from_db
#
##############################################################################
def update_configuration_from_db():
Reto Da Forno's avatar
Reto Da Forno committed
104
105
106
107
108
    # Get needed metadata from database ---
    # for all running / preparing tests
    # for each observer used in a serial configuration
    # (user remoteIp, server port, observer ip, port)
    
Reto Da Forno's avatar
Reto Da Forno committed
109
110
    proxystartport = flocklab.config.getint('serialproxy', 'startport')
    obsdataport = flocklab.config.getint('serialproxy', 'obsdataport')
Reto Da Forno's avatar
Reto Da Forno committed
111
    proxyConfig = []
112
    logger.debug("Updating configuration from DB...")
Reto Da Forno's avatar
Reto Da Forno committed
113
    try:
Reto Da Forno's avatar
Reto Da Forno committed
114
        (cn, cur) = flocklab.connect_to_db()
Reto Da Forno's avatar
Reto Da Forno committed
115
116
117
118
        cur.execute('SET time_zone="+0:00"')
    except:
        msg = "Could not connect to database"
        logger.error(msg)
Reto Da Forno's avatar
Reto Da Forno committed
119
        flocklab.error_logandexit(msg, errno.EAGAIN)
Reto Da Forno's avatar
Reto Da Forno committed
120
121
122
123
124
125
126
127
128
129
130
131
132
    try:
        # Get the XML config from the database:
        cur.execute("SELECT `testconfig_xml`, `serv_tests_key` FROM `tbl_serv_tests` WHERE (`test_status` IN ('preparing', 'running') AND `time_end_wish` >= NOW())")
        ret = cur.fetchall()
        for testconfig in ret:
            logger.debug("Create proxy config for test %d" % testconfig[1])
            # get slot mappings
            cur.execute("SELECT `observer_id`, `ethernet_address`, `slot` FROM `tbl_serv_map_test_observer_targetimages` `a` left join `tbl_serv_observer` `b` ON (`a`.`observer_fk` = `b`.`serv_observer_key`) WHERE `test_fk` = %d" % testconfig[1])
            mapret = cur.fetchall()
            mapping = {} # dict obsid -> (ip_address, port)
            for m in mapret:
                if not m[2] is None:
                    mapping[int(m[0])] = (m[1], obsdataport)
133
134
            parser = lxml.etree.XMLParser(remove_comments=True)
            tree = lxml.etree.fromstring(bytes(bytearray(testconfig[0], encoding = 'utf-8')), parser)
Reto Da Forno's avatar
Reto Da Forno committed
135
            ns = {'d': flocklab.config.get('xml', 'namespace')}
Reto Da Forno's avatar
Reto Da Forno committed
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
            logger.debug("Got XML from database.")
            ## Process serial configuration ---
            srconfs = tree.xpath('//d:serialConf', namespaces=ns)
            for srconf in srconfs:
                obsids = srconf.xpath('d:obsIds', namespaces=ns)[0].text.split()
                remoteIp = srconf.xpath('d:remoteIp', namespaces=ns)[0].text
                # Create a pair of FIFO pipes for every observer and start ncat:
                for obsid in obsids:
                    if int(obsid) in mapping:
                        proxyConfig.append(((remoteIp, proxystartport + int(obsid)),mapping[int(obsid)]))
        if len(proxyConfig) == 0:
            logger.info("No serial forwarders required.")
        else:
            logger.debug("Current proxy configuration:")
            for pc in proxyConfig:
                logger.debug("%s:%d <-> %s:%d" % (pc[0][0],pc[0][1],pc[1][0],pc[1][1]))
        return proxyConfig
    except MySQLdb.Error as err:
        msg = str(err)
        logger.error(msg)
Reto Da Forno's avatar
Reto Da Forno committed
156
        flocklab.error_logandexit(msg, errno.EIO)
Reto Da Forno's avatar
Reto Da Forno committed
157
158
159
    except:
        logger.warn("Error %s: %s" %(str(sys.exc_info()[0]), str(sys.exc_info()[1])))
        raise
160
161
162
163
164
165
166
167
168
### END update_configuration_from_db


##############################################################################
#
# class ProxyConnections
#
##############################################################################
class ProxyConnections():
Reto Da Forno's avatar
Reto Da Forno committed
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
    server_socket_process_list = {} # dict port > process
    obs_socket_list = {} # dict (obs,slot) -> socket
    server_socket_list = {} # dict (clientaddr, obs, slot) -> socket
    client_to_obs = {} # dict obs_socket -> server_socket
    obs_to_client = {} # dict server_socket -> obs_socket
    proxyConfig = []
    addlist = []
    removelist = []
    op = None
    
    def __init__(self):
        # multiprocessing events and queues
        #  for server socket processes
        self.stopevent = multiprocessing.Event()
        self.reloadevent = multiprocessing.Event()
        self.newConnectionQueue = multiprocessing.Queue()
        #  for observer reconnect process
        self.conreqQueue = multiprocessing.Queue()
        self.condoneQueue = multiprocessing.Queue()
        # start observer reconnect process
        self.op = threading.Thread(target = obs_connect_process, args=(self.conreqQueue,self.condoneQueue,self.stopevent,))
        self.op.daemon = True
        
    def reloadConfiguration(self, newconfig):
        oldconfig = self.proxyConfig
        self.proxyConfig = newconfig
        # empty observer request queue
        self.conreqQueue.put(None)
        # drop old connections
        for dc in [c for c in oldconfig if c not in newconfig]:
            logger.debug("Drop old connection %s" % str(dc))
            self.server_socket_process_list[dc[0][1]][1].set() # set stop event
            if dc[0] in self.server_socket_list and self.server_socket_list[dc[0]]:
                self.removeHandler(self.server_socket_list[dc[0]])
            elif dc[1] in self.obs_socket_list and self.obs_socket_list[dc[1]]:
                self.removeHandler(self.obs_socket_list[dc[1]])
        for dc in [c for c in oldconfig if c not in newconfig]:
            self.server_socket_process_list[dc[0][1]][0].join()
            del self.server_socket_process_list[dc[0][1]]      # remove the entry from the dictionary
        # add new connections
        for nc in [c for c in newconfig if c not in oldconfig]:
            logger.debug("Add new connection %s" % str(nc))
            self.requestListenSocket(nc[0])
            self.requestObserverSocket(nc[1])
            
    def requestListenSocket(self, addr):
        if not addr[1] in self.server_socket_process_list:
            _stopevent = multiprocessing.Event()
            lp = threading.Thread(target = listen_process, args=(addr[1],self.newConnectionQueue,_stopevent,))
            lp.daemon = True
            lp.start()
            self.server_socket_process_list[addr[1]] = (lp, _stopevent)
        
    def requestObserverSocket(self, addr):
        self.conreqQueue.put(addr)
        
    def getLists(self, is_observer):
        if is_observer:
            return self.obs_socket_list, self.server_socket_list, self.obs_to_client, self.client_to_obs
        else:
            return self.server_socket_list, self.obs_socket_list, self.client_to_obs, self.obs_to_client
    
    def removeHandler(self, conn):
        reconnect = None
        conn.shutdown(socket.SHUT_RDWR)
        conn.close()
        # remove from socket list
        for l in (self.obs_socket_list, self.server_socket_list):
            for k,s in list(l.items()):
                if s == conn:
                    del(l[k])
                    reconnectaddr = k
                    break
        # if bidirectional, remove also other socket
        if conn in self.client_to_obs: # client connetion. remove
            reconnect = False
            src_list, dst_list, src_to_dst, dst_to_src = self.getLists(False)
        elif conn in self.obs_to_client: # observer connection. try to reconnect with timeout
            reconnect = True
            src_list, dst_list, src_to_dst, dst_to_src = self.getLists(True)
        else:
            return
        self.removelist.append(conn)
        self.removelist.append(src_to_dst[conn])
        del(dst_to_src[src_to_dst[conn]])
        del(src_to_dst[conn])
        if reconnect and reconnectaddr:
            connectionConfig = [p for p in self.proxyConfig if p[1] == reconnectaddr]
            if len(connectionConfig) > 0:
                self.requestObserverSocket(connectionConfig[0][1])
    
    def addHandler(self, conn, addr, is_observer):
        if is_observer:
            connectionConfig = [p[0] for p in self.proxyConfig if p[1] == addr]
        else:
            connectionConfig = [p[1] for p in self.proxyConfig if p[0] == addr]
        if len(connectionConfig) > 0:
            src_list, dst_list, src_to_dst, dst_to_src = self.getLists(is_observer)
            connectionConfig = connectionConfig[0]
            if addr in src_list:
                conn.shutdown(socket.SHUT_RDWR)
                conn.close()
                logger.info("Connection rejected, already exists")
                return
            src_list[addr] = conn
            #logger.debug("src_list is %s" % str(src_list))
            if connectionConfig in dst_list:
                src_to_dst[conn] = dst_list[connectionConfig]
                dst_to_src[dst_list[connectionConfig]] = conn
                # forward on this connection
                self.addlist.append(conn)
                self.addlist.append(src_to_dst[conn])
                logger.info("Established connection %s" % (str((connectionConfig, addr))))
        else:
            conn.close()
            logger.info("Connection not for us, addr was %s" % str(addr))
285

Reto Da Forno's avatar
Reto Da Forno committed
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
    def getChanges(self):
        a = self.addlist
        r = self.removelist
        self.addlist = []
        self.removelist = []
        return a, r
    
    def forward(self, data, src_conn):
        if src_conn in self.client_to_obs and self.client_to_obs[src_conn]:
            self.client_to_obs[src_conn].send(data)
        elif src_conn in self.obs_to_client and self.obs_to_client[src_conn]:
            self.obs_to_client[src_conn].send(data)
    
    def run(self):
        global stopevent
        global reloadevent
        stopevent = self.stopevent
        reloadevent = self.reloadevent
        self.op.start()
        logger.info("FlockLab serial proxy started.")
        
        # infinite while loop
        inputs = [self.newConnectionQueue._reader, self.condoneQueue._reader]
        while not stopevent.is_set():
            try:
                (readable, writable, ex) = select.select(inputs,[],[],10)   # 10s timeout
            except select.error as e:
                if e[0] != errno.EINTR:
                    raise
            except Exception as e:
                logger.error("Error %s, %s" % (str(e), type(e)))
                raise
            
            # config reload necessary?
            if reloadevent.is_set():
                reloadevent.clear()
                logger.info("Reloading configuration...")
                newProxyConfig = update_configuration_from_db()
                self.reloadConfiguration(newProxyConfig)
                if len(newProxyConfig) == 0:
                    logger.info("No running tests, shutting down serial proxy...")
                    stopevent.set()
                readable = []
            
            # check new connections
            try:
                for i in readable:
                    # new connection from user
                    if i == self.newConnectionQueue._reader: 
                        try:
                            conn, addr = self.newConnectionQueue.get(False)
                            self.addHandler(conn, addr, is_observer = False)
                        except queue.Empty: 
                            pass
                    # new connection to observer
                    elif i == self.condoneQueue._reader:
                        try:
                            conn, addr = self.condoneQueue.get(False)
                            self.addHandler(conn, addr, is_observer = True)
                        except queue.Empty: 
Reto Da Forno's avatar
Reto Da Forno committed
346
                            pass
Reto Da Forno's avatar
Reto Da Forno committed
347
348
349
350
351
352
                    # assume it is a socket, do forwarding
                    else:
                        m = ''
                        try:
                            m = i.recv(1024)
                            logger.debug("received %d bytes from socket %s" % (len(m), str(i)))
353
                        except socket.error as serr:
Reto Da Forno's avatar
Reto Da Forno committed
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
                            # user probably disconnected, don't generate an error message
                            logger.debug("socket_error")
                            break
                        except Exception as e:
                            logger.error("error %s, %s" % (str(e), type(e)))
                        # a socket without data available is from a client that has disconnected
                        if len(m) == 0:
                            self.removeHandler(i)
                        else:
                            self.forward(m, i)
                # do book keeping
                iadd, iremove = self.getChanges()
                for r in iremove:
                    logger.debug("remove socket %s" %str(r))
                    inputs.remove(r)
                for a in iadd:
                    logger.debug("add socket %s" %str(a))
                    inputs.append(a)
            except:
                logger.error("Error %s, %s" % (str(e), type(e)))
            
        self.reloadConfiguration([])
        self.op.join()
        
        logger.info("Serial proxy stopped.")
379
380
### END class ProxyConnections

Reto Da Forno's avatar
Reto Da Forno committed
381

382
383
384
385
386
387
##############################################################################
#
# Start proxy
#
##############################################################################
def start_proxy():
Reto Da Forno's avatar
Reto Da Forno committed
388
389
390
391
392
393
394
395
396
    proxyConfig = update_configuration_from_db()
    if len(proxyConfig) == 0:
        logger.info("No connections, exiting...")
        return
    # Daemonize the process ---
    daemon.daemonize(None, closedesc=False)
    # Catch kill signals ---
    signal.signal(signal.SIGTERM, sigterm_handler)
    signal.signal(signal.SIGINT,  sigterm_handler)
397
    logger.info("Serial proxy daemon started.")
Reto Da Forno's avatar
Reto Da Forno committed
398
399
400
    proxy = ProxyConnections()
    proxy.reloadConfiguration(proxyConfig)
    proxy.run()
401
### END start_proxy
Reto Da Forno's avatar
Reto Da Forno committed
402
403


404
405
406
407
408
409
##############################################################################
#
# Stop proxy
#
##############################################################################
def sig_proxy(signum):
Reto Da Forno's avatar
Reto Da Forno committed
410
    # Get oldest running instance of the proxy for the selected test ID which is the main process and send it the terminate signal:
411
412
413
414
415
416
417
418
419
420
421
    searchterm = "%s" % __file__
    cmd = ['pgrep', '-o', '-f', searchterm]
    p = subprocess.Popen(cmd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.PIPE, universal_newlines=True)
    out, err = p.communicate()
    if (p.returncode == 0):
        pid = int(out)
        # Do not stop this instance if it is the only one running:
        if (pid == os.getpid()):
            return errno.ENOPKG
    else:
        logger.warn("Command failed: %s" % (str(cmd)))
Reto Da Forno's avatar
Reto Da Forno committed
422
        return errno.ENOPKG
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
    # Signal the process to stop:
    if (pid > 0):
        logger.debug("Sending signal %d to process %d" %(signum, pid))
        try:
            os.kill(pid, signum)
            if signum == signal.SIGTERM:
                logger.debug("Waiting for process to finish...")
                # wait for process to finish (timeout..)
                shutdown_timeout = flocklab.config.getint("serialproxy", "shutdown_timeout")
                pidpath = "/proc/%d"%pid
                while os.path.exists(pidpath) & (shutdown_timeout>0):
                    time.sleep(1)
                    shutdown_timeout = shutdown_timeout - 1
                if os.path.exists(pidpath):
                    logger.warn("Serial proxy is still running, sending it the SIGKILL signal...")
                    os.kill(pid, signal.SIGKILL)
        except:
            logger.warn("Failed to send SIGKILL: %s: %s" % (str(sys.exc_info()[0]), str(sys.exc_info()[1])))
Reto Da Forno's avatar
Reto Da Forno committed
441
    
442
    return flocklab.SUCCESS
443
444
445
446
447
448
449
450
451
### END sig_proxy


##############################################################################
#
# Usage
#
##############################################################################
def usage():
Reto Da Forno's avatar
Reto Da Forno committed
452
    print("Usage: %s --notify/start/stop [--debug] [--help]" % __file__)
Reto Da Forno's avatar
Reto Da Forno committed
453
454
455
456
457
458
    print("Options:")
    print("  --notify\t\t\tNotifies the proxy of a change in the database.")
    print("  --start\t\t\tStarts the background process of the proxy.")
    print("  --stop\t\t\tCauses the program to stop a possibly running instance of the serial proxy.")
    print("  --debug\t\t\tOptional. Print debug messages to log.")
    print("  --help\t\t\tOptional. Print this help.")
459
460
461
462
463
464
465
466
467
### END usage()


##############################################################################
#
# Main
#
##############################################################################
def main(argv):
Reto Da Forno's avatar
Reto Da Forno committed
468
469
470
471
472
473
474
475
476
477
    
    ### Get global variables ###
    global logger
    global debug
    
    stop = False
    start = False
    notify = False
    
    # Get logger:
478
479
    logger = flocklab.get_logger(debug=debug)
    
Reto Da Forno's avatar
Reto Da Forno committed
480
    # Get the config file ---
481
482
    flocklab.load_config()
    
Reto Da Forno's avatar
Reto Da Forno committed
483
484
485
486
487
488
489
490
491
    # Get command line parameters ---
    try:
        opts, args = getopt.getopt(argv, "hnsed", ["help", "notify", "start", "stop", "debug"])
    except getopt.GetoptError as err:
        print(str(err))
        logger.warn(str(err))
        usage()
        sys.exit(errno.EINVAL)
    except:
492
493
        logger.error("Error when getting arguments: %s: %s" %(str(sys.exc_info()[0]), str(sys.exc_info()[1])), errno.EAGAIN)
        sys.exit(errno.EINVAL)
Reto Da Forno's avatar
Reto Da Forno committed
494
495
496
    for opt, arg in opts:
        if opt in ("-h", "--help"):
            usage()
497
            sys.exit(flocklab.SUCCESS)
Reto Da Forno's avatar
Reto Da Forno committed
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
        elif opt in ("-d", "--debug"):
            debug = True
            logger.setLevel(logging.DEBUG)
        elif opt in ("-e", "--stop"):
            stop = True
        elif opt in ("-s", "--start"):
            start = True
        elif opt in ("-n", "--notify"):
            notify = True
        else:
            print("Wrong API usage")
            logger.warn("Wrong API usage")
            sys.exit(errno.EINVAL)
    
    # Start / stop the proxy ---
513
    ret = flocklab.SUCCESS
Reto Da Forno's avatar
Reto Da Forno committed
514
515
    if stop:
        ret = sig_proxy(signal.SIGTERM)
516
        logger.debug("SIGTERM sent to serial proxy daemon.")
Reto Da Forno's avatar
Reto Da Forno committed
517
518
    elif notify:
        ret = sig_proxy(signal.SIGINT)
519
520
521
        logger.debug("SIGINT sent to serial proxy daemon.")
    
    if start or (notify and ret == errno.ENOPKG):
Reto Da Forno's avatar
Reto Da Forno committed
522
        # Start the proxy processes:
523
        ret = flocklab.SUCCESS
Reto Da Forno's avatar
Reto Da Forno committed
524
        try:
525
            logger.debug("Starting serial proxy...")
Reto Da Forno's avatar
Reto Da Forno committed
526
527
            start_proxy()
        except Exception:
528
529
            logger.error("Failed to start serial proxy daemon.\n%s" % traceback.format_exc())
            ret = flocklab.FAILED
Reto Da Forno's avatar
Reto Da Forno committed
530
531
        
    sys.exit(ret)
532
533
### END main()

Reto Da Forno's avatar
Reto Da Forno committed
534

535
if __name__ == "__main__":
Reto Da Forno's avatar
Reto Da Forno committed
536
537
538
    try:
        main(sys.argv[1:])
    except Exception:
539
        flocklab.error_logandexit("Encountered error: %s: %s\n%s\nCommand line was: %s" % (str(sys.exc_info()[0]), str(sys.exc_info()[1]), traceback.format_exc(), str(sys.argv)))