process.py 24 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688
  1. #
  2. # BitBake Process based server.
  3. #
  4. # Copyright (C) 2010 Bob Foerster <robert@erafx.com>
  5. #
  6. # SPDX-License-Identifier: GPL-2.0-only
  7. #
  8. """
  9. This module implements a multiprocessing.Process based server for bitbake.
  10. """
  11. import bb
  12. import bb.event
  13. import logging
  14. import multiprocessing
  15. import threading
  16. import array
  17. import os
  18. import sys
  19. import time
  20. import select
  21. import socket
  22. import subprocess
  23. import errno
  24. import re
  25. import datetime
  26. import bb.server.xmlrpcserver
  27. from bb import daemonize
  28. from multiprocessing import queues
  29. logger = logging.getLogger('BitBake')
  30. class ProcessTimeout(SystemExit):
  31. pass
  32. class ProcessServer():
  33. profile_filename = "profile.log"
  34. profile_processed_filename = "profile.log.processed"
  35. def __init__(self, lock, sock, sockname, server_timeout, xmlrpcinterface):
  36. self.command_channel = False
  37. self.command_channel_reply = False
  38. self.quit = False
  39. self.heartbeat_seconds = 1 # default, BB_HEARTBEAT_EVENT will be checked once we have a datastore.
  40. self.next_heartbeat = time.time()
  41. self.event_handle = None
  42. self.hadanyui = False
  43. self.haveui = False
  44. self.maxuiwait = 30
  45. self.xmlrpc = False
  46. self._idlefuns = {}
  47. self.bitbake_lock = lock
  48. self.sock = sock
  49. self.sockname = sockname
  50. self.server_timeout = server_timeout
  51. self.timeout = self.server_timeout
  52. self.xmlrpcinterface = xmlrpcinterface
  53. def register_idle_function(self, function, data):
  54. """Register a function to be called while the server is idle"""
  55. assert hasattr(function, '__call__')
  56. self._idlefuns[function] = data
  57. def run(self):
  58. if self.xmlrpcinterface[0]:
  59. self.xmlrpc = bb.server.xmlrpcserver.BitBakeXMLRPCServer(self.xmlrpcinterface, self.cooker, self)
  60. print("Bitbake XMLRPC server address: %s, server port: %s" % (self.xmlrpc.host, self.xmlrpc.port))
  61. try:
  62. self.bitbake_lock.seek(0)
  63. self.bitbake_lock.truncate()
  64. if self.xmlrpc:
  65. self.bitbake_lock.write("%s %s:%s\n" % (os.getpid(), self.xmlrpc.host, self.xmlrpc.port))
  66. else:
  67. self.bitbake_lock.write("%s\n" % (os.getpid()))
  68. self.bitbake_lock.flush()
  69. except Exception as e:
  70. print("Error writing to lock file: %s" % str(e))
  71. pass
  72. if self.cooker.configuration.profile:
  73. try:
  74. import cProfile as profile
  75. except:
  76. import profile
  77. prof = profile.Profile()
  78. ret = profile.Profile.runcall(prof, self.main)
  79. prof.dump_stats("profile.log")
  80. bb.utils.process_profilelog("profile.log")
  81. print("Raw profiling information saved to profile.log and processed statistics to profile.log.processed")
  82. else:
  83. ret = self.main()
  84. return ret
  85. def main(self):
  86. self.cooker.pre_serve()
  87. bb.utils.set_process_name("Cooker")
  88. ready = []
  89. newconnections = []
  90. self.controllersock = False
  91. fds = [self.sock]
  92. if self.xmlrpc:
  93. fds.append(self.xmlrpc)
  94. seendata = False
  95. print("Entering server connection loop")
  96. def disconnect_client(self, fds):
  97. print("Disconnecting Client")
  98. if self.controllersock:
  99. fds.remove(self.controllersock)
  100. self.controllersock.close()
  101. self.controllersock = False
  102. if self.haveui:
  103. fds.remove(self.command_channel)
  104. bb.event.unregister_UIHhandler(self.event_handle, True)
  105. self.command_channel_reply.writer.close()
  106. self.event_writer.writer.close()
  107. self.command_channel.close()
  108. self.command_channel = False
  109. del self.event_writer
  110. self.lastui = time.time()
  111. self.cooker.clientComplete()
  112. self.haveui = False
  113. ready = select.select(fds,[],[],0)[0]
  114. if newconnections:
  115. print("Starting new client")
  116. conn = newconnections.pop(-1)
  117. fds.append(conn)
  118. self.controllersock = conn
  119. elif self.timeout is None and not ready:
  120. print("No timeout, exiting.")
  121. self.quit = True
  122. self.lastui = time.time()
  123. while not self.quit:
  124. if self.sock in ready:
  125. while select.select([self.sock],[],[],0)[0]:
  126. controllersock, address = self.sock.accept()
  127. if self.controllersock:
  128. print("Queuing %s (%s)" % (str(ready), str(newconnections)))
  129. newconnections.append(controllersock)
  130. else:
  131. print("Accepting %s (%s)" % (str(ready), str(newconnections)))
  132. self.controllersock = controllersock
  133. fds.append(controllersock)
  134. if self.controllersock in ready:
  135. try:
  136. print("Processing Client")
  137. ui_fds = recvfds(self.controllersock, 3)
  138. print("Connecting Client")
  139. # Where to write events to
  140. writer = ConnectionWriter(ui_fds[0])
  141. self.event_handle = bb.event.register_UIHhandler(writer, True)
  142. self.event_writer = writer
  143. # Where to read commands from
  144. reader = ConnectionReader(ui_fds[1])
  145. fds.append(reader)
  146. self.command_channel = reader
  147. # Where to send command return values to
  148. writer = ConnectionWriter(ui_fds[2])
  149. self.command_channel_reply = writer
  150. self.haveui = True
  151. self.hadanyui = True
  152. except (EOFError, OSError):
  153. disconnect_client(self, fds)
  154. if not self.timeout == -1.0 and not self.haveui and self.timeout and \
  155. (self.lastui + self.timeout) < time.time():
  156. print("Server timeout, exiting.")
  157. self.quit = True
  158. # If we don't see a UI connection within maxuiwait, its unlikely we're going to see
  159. # one. We have had issue with processes hanging indefinitely so timing out UI-less
  160. # servers is useful.
  161. if not self.hadanyui and not self.xmlrpc and not self.timeout and (self.lastui + self.maxuiwait) < time.time():
  162. print("No UI connection within max timeout, exiting to avoid infinite loop.")
  163. self.quit = True
  164. if self.command_channel in ready:
  165. try:
  166. command = self.command_channel.get()
  167. except EOFError:
  168. # Client connection shutting down
  169. ready = []
  170. disconnect_client(self, fds)
  171. continue
  172. if command[0] == "terminateServer":
  173. self.quit = True
  174. continue
  175. try:
  176. print("Running command %s" % command)
  177. self.command_channel_reply.send(self.cooker.command.runCommand(command))
  178. except Exception as e:
  179. logger.exception('Exception in server main event loop running command %s (%s)' % (command, str(e)))
  180. if self.xmlrpc in ready:
  181. self.xmlrpc.handle_requests()
  182. if not seendata and hasattr(self.cooker, "data"):
  183. heartbeat_event = self.cooker.data.getVar('BB_HEARTBEAT_EVENT')
  184. if heartbeat_event:
  185. try:
  186. self.heartbeat_seconds = float(heartbeat_event)
  187. except:
  188. bb.warn('Ignoring invalid BB_HEARTBEAT_EVENT=%s, must be a float specifying seconds.' % heartbeat_event)
  189. self.timeout = self.server_timeout or self.cooker.data.getVar('BB_SERVER_TIMEOUT')
  190. try:
  191. if self.timeout:
  192. self.timeout = float(self.timeout)
  193. except:
  194. bb.warn('Ignoring invalid BB_SERVER_TIMEOUT=%s, must be a float specifying seconds.' % self.timeout)
  195. seendata = True
  196. ready = self.idle_commands(.1, fds)
  197. if len(threading.enumerate()) != 1:
  198. print("More than one thread left?: " + str(threading.enumerate()))
  199. print("Exiting")
  200. # Remove the socket file so we don't get any more connections to avoid races
  201. try:
  202. os.unlink(self.sockname)
  203. except:
  204. pass
  205. self.sock.close()
  206. try:
  207. self.cooker.shutdown(True)
  208. self.cooker.notifier.stop()
  209. self.cooker.confignotifier.stop()
  210. except:
  211. pass
  212. self.cooker.post_serve()
  213. # Flush logs before we release the lock
  214. sys.stdout.flush()
  215. sys.stderr.flush()
  216. # Finally release the lockfile but warn about other processes holding it open
  217. lock = self.bitbake_lock
  218. lockfile = lock.name
  219. lock.close()
  220. lock = None
  221. while not lock:
  222. with bb.utils.timeout(3):
  223. lock = bb.utils.lockfile(lockfile, shared=False, retry=False, block=True)
  224. if lock:
  225. # We hold the lock so we can remove the file (hide stale pid data)
  226. # via unlockfile.
  227. bb.utils.unlockfile(lock)
  228. return
  229. if not lock:
  230. # Some systems may not have lsof available
  231. procs = None
  232. try:
  233. procs = subprocess.check_output(["lsof", '-w', lockfile], stderr=subprocess.STDOUT)
  234. except OSError as e:
  235. if e.errno != errno.ENOENT:
  236. raise
  237. if procs is None:
  238. # Fall back to fuser if lsof is unavailable
  239. try:
  240. procs = subprocess.check_output(["fuser", '-v', lockfile], stderr=subprocess.STDOUT)
  241. except OSError as e:
  242. if e.errno != errno.ENOENT:
  243. raise
  244. msg = "Delaying shutdown due to active processes which appear to be holding bitbake.lock"
  245. if procs:
  246. msg += ":\n%s" % str(procs)
  247. print(msg)
  248. def idle_commands(self, delay, fds=None):
  249. nextsleep = delay
  250. if not fds:
  251. fds = []
  252. for function, data in list(self._idlefuns.items()):
  253. try:
  254. retval = function(self, data, False)
  255. if retval is False:
  256. del self._idlefuns[function]
  257. nextsleep = None
  258. elif retval is True:
  259. nextsleep = None
  260. elif isinstance(retval, float) and nextsleep:
  261. if (retval < nextsleep):
  262. nextsleep = retval
  263. elif nextsleep is None:
  264. continue
  265. else:
  266. fds = fds + retval
  267. except SystemExit:
  268. raise
  269. except Exception as exc:
  270. if not isinstance(exc, bb.BBHandledException):
  271. logger.exception('Running idle function')
  272. del self._idlefuns[function]
  273. self.quit = True
  274. # Create new heartbeat event?
  275. now = time.time()
  276. if now >= self.next_heartbeat:
  277. # We might have missed heartbeats. Just trigger once in
  278. # that case and continue after the usual delay.
  279. self.next_heartbeat += self.heartbeat_seconds
  280. if self.next_heartbeat <= now:
  281. self.next_heartbeat = now + self.heartbeat_seconds
  282. if hasattr(self.cooker, "data"):
  283. heartbeat = bb.event.HeartbeatEvent(now)
  284. bb.event.fire(heartbeat, self.cooker.data)
  285. if nextsleep and now + nextsleep > self.next_heartbeat:
  286. # Shorten timeout so that we we wake up in time for
  287. # the heartbeat.
  288. nextsleep = self.next_heartbeat - now
  289. if nextsleep is not None:
  290. if self.xmlrpc:
  291. nextsleep = self.xmlrpc.get_timeout(nextsleep)
  292. try:
  293. return select.select(fds,[],[],nextsleep)[0]
  294. except InterruptedError:
  295. # Ignore EINTR
  296. return []
  297. else:
  298. return select.select(fds,[],[],0)[0]
  299. class ServerCommunicator():
  300. def __init__(self, connection, recv):
  301. self.connection = connection
  302. self.recv = recv
  303. def runCommand(self, command):
  304. self.connection.send(command)
  305. if not self.recv.poll(30):
  306. logger.info("No reply from server in 30s")
  307. if not self.recv.poll(30):
  308. raise ProcessTimeout("Timeout while waiting for a reply from the bitbake server (60s)")
  309. return self.recv.get()
  310. def updateFeatureSet(self, featureset):
  311. _, error = self.runCommand(["setFeatures", featureset])
  312. if error:
  313. logger.error("Unable to set the cooker to the correct featureset: %s" % error)
  314. raise BaseException(error)
  315. def getEventHandle(self):
  316. handle, error = self.runCommand(["getUIHandlerNum"])
  317. if error:
  318. logger.error("Unable to get UI Handler Number: %s" % error)
  319. raise BaseException(error)
  320. return handle
  321. def terminateServer(self):
  322. self.connection.send(['terminateServer'])
  323. return
  324. class BitBakeProcessServerConnection(object):
  325. def __init__(self, ui_channel, recv, eq, sock):
  326. self.connection = ServerCommunicator(ui_channel, recv)
  327. self.events = eq
  328. # Save sock so it doesn't get gc'd for the life of our connection
  329. self.socket_connection = sock
  330. def terminate(self):
  331. self.socket_connection.close()
  332. self.connection.connection.close()
  333. self.connection.recv.close()
  334. return
  335. class BitBakeServer(object):
  336. start_log_format = '--- Starting bitbake server pid %s at %s ---'
  337. start_log_datetime_format = '%Y-%m-%d %H:%M:%S.%f'
  338. def __init__(self, lock, sockname, featureset, server_timeout, xmlrpcinterface):
  339. self.server_timeout = server_timeout
  340. self.xmlrpcinterface = xmlrpcinterface
  341. self.featureset = featureset
  342. self.sockname = sockname
  343. self.bitbake_lock = lock
  344. self.readypipe, self.readypipein = os.pipe()
  345. # Place the log in the builddirectory alongside the lock file
  346. logfile = os.path.join(os.path.dirname(self.bitbake_lock.name), "bitbake-cookerdaemon.log")
  347. startdatetime = datetime.datetime.now()
  348. bb.daemonize.createDaemon(self._startServer, logfile)
  349. self.bitbake_lock.close()
  350. os.close(self.readypipein)
  351. ready = ConnectionReader(self.readypipe)
  352. r = ready.poll(5)
  353. if not r:
  354. bb.note("Bitbake server didn't start within 5 seconds, waiting for 90")
  355. r = ready.poll(90)
  356. if r:
  357. try:
  358. r = ready.get()
  359. except EOFError:
  360. # Trap the child exitting/closing the pipe and error out
  361. r = None
  362. if not r or r[0] != "r":
  363. ready.close()
  364. bb.error("Unable to start bitbake server (%s)" % str(r))
  365. if os.path.exists(logfile):
  366. logstart_re = re.compile(self.start_log_format % ('([0-9]+)', '([0-9-]+ [0-9:.]+)'))
  367. started = False
  368. lines = []
  369. lastlines = []
  370. with open(logfile, "r") as f:
  371. for line in f:
  372. if started:
  373. lines.append(line)
  374. else:
  375. lastlines.append(line)
  376. res = logstart_re.match(line.rstrip())
  377. if res:
  378. ldatetime = datetime.datetime.strptime(res.group(2), self.start_log_datetime_format)
  379. if ldatetime >= startdatetime:
  380. started = True
  381. lines.append(line)
  382. if len(lastlines) > 60:
  383. lastlines = lastlines[-60:]
  384. if lines:
  385. if len(lines) > 60:
  386. bb.error("Last 60 lines of server log for this session (%s):\n%s" % (logfile, "".join(lines[-60:])))
  387. else:
  388. bb.error("Server log for this session (%s):\n%s" % (logfile, "".join(lines)))
  389. elif lastlines:
  390. bb.error("Server didn't start, last 60 loglines (%s):\n%s" % (logfile, "".join(lastlines)))
  391. else:
  392. bb.error("%s doesn't exist" % logfile)
  393. raise SystemExit(1)
  394. ready.close()
  395. def _startServer(self):
  396. print(self.start_log_format % (os.getpid(), datetime.datetime.now().strftime(self.start_log_datetime_format)))
  397. sys.stdout.flush()
  398. try:
  399. # Create server control socket
  400. if os.path.exists(self.sockname):
  401. os.unlink(self.sockname)
  402. sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
  403. # AF_UNIX has path length issues so chdir here to workaround
  404. cwd = os.getcwd()
  405. try:
  406. os.chdir(os.path.dirname(self.sockname))
  407. sock.bind(os.path.basename(self.sockname))
  408. finally:
  409. os.chdir(cwd)
  410. sock.listen(1)
  411. server = ProcessServer(self.bitbake_lock, sock, self.sockname, self.server_timeout, self.xmlrpcinterface)
  412. os.close(self.readypipe)
  413. writer = ConnectionWriter(self.readypipein)
  414. try:
  415. self.cooker = bb.cooker.BBCooker(self.featureset, server.register_idle_function)
  416. except bb.BBHandledException:
  417. return None
  418. writer.send("r")
  419. writer.close()
  420. server.cooker = self.cooker
  421. print("Started bitbake server pid %d" % os.getpid())
  422. sys.stdout.flush()
  423. server.run()
  424. finally:
  425. # Flush any ,essages/errors to the logfile before exit
  426. sys.stdout.flush()
  427. sys.stderr.flush()
  428. def connectProcessServer(sockname, featureset):
  429. # Connect to socket
  430. sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
  431. # AF_UNIX has path length issues so chdir here to workaround
  432. cwd = os.getcwd()
  433. readfd = writefd = readfd1 = writefd1 = readfd2 = writefd2 = None
  434. eq = command_chan_recv = command_chan = None
  435. sock.settimeout(10)
  436. try:
  437. try:
  438. os.chdir(os.path.dirname(sockname))
  439. finished = False
  440. while not finished:
  441. try:
  442. sock.connect(os.path.basename(sockname))
  443. finished = True
  444. except IOError as e:
  445. if e.errno == errno.EWOULDBLOCK:
  446. pass
  447. raise
  448. finally:
  449. os.chdir(cwd)
  450. # Send an fd for the remote to write events to
  451. readfd, writefd = os.pipe()
  452. eq = BBUIEventQueue(readfd)
  453. # Send an fd for the remote to recieve commands from
  454. readfd1, writefd1 = os.pipe()
  455. command_chan = ConnectionWriter(writefd1)
  456. # Send an fd for the remote to write commands results to
  457. readfd2, writefd2 = os.pipe()
  458. command_chan_recv = ConnectionReader(readfd2)
  459. sendfds(sock, [writefd, readfd1, writefd2])
  460. server_connection = BitBakeProcessServerConnection(command_chan, command_chan_recv, eq, sock)
  461. # Close the ends of the pipes we won't use
  462. for i in [writefd, readfd1, writefd2]:
  463. os.close(i)
  464. server_connection.connection.updateFeatureSet(featureset)
  465. except (Exception, SystemExit) as e:
  466. if command_chan_recv:
  467. command_chan_recv.close()
  468. if command_chan:
  469. command_chan.close()
  470. for i in [writefd, readfd1, writefd2]:
  471. try:
  472. if i:
  473. os.close(i)
  474. except OSError:
  475. pass
  476. sock.close()
  477. raise
  478. return server_connection
  479. def sendfds(sock, fds):
  480. '''Send an array of fds over an AF_UNIX socket.'''
  481. fds = array.array('i', fds)
  482. msg = bytes([len(fds) % 256])
  483. sock.sendmsg([msg], [(socket.SOL_SOCKET, socket.SCM_RIGHTS, fds)])
  484. def recvfds(sock, size):
  485. '''Receive an array of fds over an AF_UNIX socket.'''
  486. a = array.array('i')
  487. bytes_size = a.itemsize * size
  488. msg, ancdata, flags, addr = sock.recvmsg(1, socket.CMSG_LEN(bytes_size))
  489. if not msg and not ancdata:
  490. raise EOFError
  491. try:
  492. if len(ancdata) != 1:
  493. raise RuntimeError('received %d items of ancdata' %
  494. len(ancdata))
  495. cmsg_level, cmsg_type, cmsg_data = ancdata[0]
  496. if (cmsg_level == socket.SOL_SOCKET and
  497. cmsg_type == socket.SCM_RIGHTS):
  498. if len(cmsg_data) % a.itemsize != 0:
  499. raise ValueError
  500. a.frombytes(cmsg_data)
  501. assert len(a) % 256 == msg[0]
  502. return list(a)
  503. except (ValueError, IndexError):
  504. pass
  505. raise RuntimeError('Invalid data received')
  506. class BBUIEventQueue:
  507. def __init__(self, readfd):
  508. self.eventQueue = []
  509. self.eventQueueLock = threading.Lock()
  510. self.eventQueueNotify = threading.Event()
  511. self.reader = ConnectionReader(readfd)
  512. self.t = threading.Thread()
  513. self.t.setDaemon(True)
  514. self.t.run = self.startCallbackHandler
  515. self.t.start()
  516. def getEvent(self):
  517. self.eventQueueLock.acquire()
  518. if len(self.eventQueue) == 0:
  519. self.eventQueueLock.release()
  520. return None
  521. item = self.eventQueue.pop(0)
  522. if len(self.eventQueue) == 0:
  523. self.eventQueueNotify.clear()
  524. self.eventQueueLock.release()
  525. return item
  526. def waitEvent(self, delay):
  527. self.eventQueueNotify.wait(delay)
  528. return self.getEvent()
  529. def queue_event(self, event):
  530. self.eventQueueLock.acquire()
  531. self.eventQueue.append(event)
  532. self.eventQueueNotify.set()
  533. self.eventQueueLock.release()
  534. def send_event(self, event):
  535. self.queue_event(pickle.loads(event))
  536. def startCallbackHandler(self):
  537. bb.utils.set_process_name("UIEventQueue")
  538. while True:
  539. try:
  540. self.reader.wait()
  541. event = self.reader.get()
  542. self.queue_event(event)
  543. except EOFError:
  544. # Easiest way to exit is to close the file descriptor to cause an exit
  545. break
  546. self.reader.close()
  547. class ConnectionReader(object):
  548. def __init__(self, fd):
  549. self.reader = multiprocessing.connection.Connection(fd, writable=False)
  550. self.rlock = multiprocessing.Lock()
  551. def wait(self, timeout=None):
  552. return multiprocessing.connection.wait([self.reader], timeout)
  553. def poll(self, timeout=None):
  554. return self.reader.poll(timeout)
  555. def get(self):
  556. with self.rlock:
  557. res = self.reader.recv_bytes()
  558. return multiprocessing.reduction.ForkingPickler.loads(res)
  559. def fileno(self):
  560. return self.reader.fileno()
  561. def close(self):
  562. return self.reader.close()
  563. class ConnectionWriter(object):
  564. def __init__(self, fd):
  565. self.writer = multiprocessing.connection.Connection(fd, readable=False)
  566. self.wlock = multiprocessing.Lock()
  567. # Why bb.event needs this I have no idea
  568. self.event = self
  569. def send(self, obj):
  570. obj = multiprocessing.reduction.ForkingPickler.dumps(obj)
  571. with self.wlock:
  572. self.writer.send_bytes(obj)
  573. def fileno(self):
  574. return self.writer.fileno()
  575. def close(self):
  576. return self.writer.close()