View Issue Details

IDProjectCategoryView StatusLast Update
0001936SOGoOpenChange backendpublic2015-05-25 19:52
ReporterjrabyAssigned Toludovic  
PrioritynormalSeverityminorReproducibilityhave not tried
Status resolvedResolutionsuspended 
Summary0001936: ocsmanager spins if samba is not running
Description

If for some reason SAMBA_HOST is not reachable by ocsmanager, the process spins infinitely, waiting for /var/cache/ntlmauthhandler/ntlm-localhost to be created.

Normally, the process would spin a bit and then connect to the socket, but for some reason the child responsible for creating it dies.
Also, since the parent closes every fd before forking, the logging in the child seems a bit broken:

<pre>
24075 write(23, "NTLMAuthHandler daemon spawned with pid 24075", 45 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 sendto(24, "HTTP/1.0 500 Internal Server Error\r\n", 36, 0, NULL, 0 <unfinished ...>
24075 <... sendto resumed> ) = -1 EBADF (Bad file descriptor)
24075 close(28 <unfinished ...>
24075 <... close resumed> ) = -1 EBADF (Bad file descriptor)
24075 close(27 <unfinished ...>
24075 <... close resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(23, "close failed in file object destructor:\n", 40 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(2, "close failed in file object destructor:\n", 40 <unfinished ...>
24075 <... write resumed> ) = 40
24075 write(23, "IOError", 7) = -1 EBADF (Bad file descriptor)
24075 write(23, "----------------------------------------", 40 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(23, "Unexpected exception in worker <function <lambda> at 0x2baa500>", 63) = -1 EBADF (Bad file descriptor)
24075 sendto(24, "HTTP/1.0 500 Internal Server Error\r\n", 36, 0, NULL, 0 <unfinished ...>
24075 <... sendto resumed> ) = -1 EBADF (Bad file descriptor)
24075 stat("/usr/lib64/python2.6/threading.py", <unfinished ...>
24075 <... stat resumed> {st_mode=S_IFREG|0644, st_size=31808, ...}) = 0
24075 open("/usr/lib64/python2.6/threading.py", O_RDONLY <unfinished ...>
24075 <... open resumed> ) = 3
24075 fstat(3, {st_mode=S_IFREG|0644, st_size=31808, ...}) = 0
24075 fstat(3, <unfinished ...>
24075 <... fstat resumed> {st_mode=S_IFREG|0644, st_size=31808, ...}) = 0
24075 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
24075 <... mmap resumed> ) = 0x7f33908e6000
24075 read(3, <unfinished ...>
24075 <... read resumed> "\"\"\"Thread module emulating a subset of Java's threading model.\"\"\"\n\nimport sys as _sys\n\ntry:\n import thread\nexcept Imp"..., 8192) = 8192
24075 read(3, <unfinished ...>
24075 <... read resumed> "bug:\n self._note(\"%s.wait(%s): timed out\", self, timeout)\n try:\n "..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "\n\n# Active thread administration\n_active_limbo_lock = _allocate_lock()\n_active = {} # maps thread id to Thread object"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "ted.set()\n _active_limbo_lock.acquire()\n _active[self.ident] = self\n del _limbo[self]"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "nstance of _MainThread is always created by 'threading'. This\n # gets overwritten the instant an instance of Thr"..., 4096) = 4096
24075 read(3, "}):\n Thread.
init__(self)\n self.interval = interval\n self.function = function\n self.args = "..., 4096) = 4096
24075 read(3, "nces to others.\n new_active = {}\n current = current_thread()\n with _active_limbo_lock:\n for thread in _a"..., 4096) = 3136
24075 read(3, <unfinished ...>
24075 <... read resumed> "", 4096) = 0
24075 close(3 <unfinished ...>
24075 <... close resumed> ) = 0
24075 munmap(0x7f33908e6000, 4096 <unfinished ...>
24075 <... munmap resumed> ) = 0
24075 stat("/usr/lib64/python2.6/threading.py", <unfinished ...>
24075 <... stat resumed> {st_mode=S_IFREG|0644, st_size=31808, ...}) = 0
24075 stat("/usr/lib/python2.6/site-packages/paste/httpserver.py", <unfinished ...>
24075 <... stat resumed> {st_mode=S_IFREG|0644, st_size=55662, ...}) = 0
24075 open("/usr/lib/python2.6/site-packages/paste/httpserver.py", O_RDONLY) = 3
24075 fstat(3, {st_mode=S_IFREG|0644, st_size=55662, ...}) = 0
24075 fstat(3, {st_mode=S_IFREG|0644, st_size=55662, ...}) = 0
24075 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f33908e6000
24075 read(3, "# (c) 2005 Ian Bicking and contributors; written for Paste (http://pythonpaste.org)\n# Licensed under the MIT license: ht"..., 8192) = 8192
24075 read(3, "T_NAME': '' # application is root of server\n ,'PATH_INFO': path\n ,'QUERY_STRING': query\n "..., 4096) = 4096
24075 read(3, ")\nexcept ImportError:\n # Do not require pyOpenSSL to be installed, but disable SSL\n # functionality in that case.\n"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "application``.\n \"\"\"\n server_version = 'PasteWSGIServer/' +
version__\n\n def handle_one_request(self):\n "..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "ads should get cleaned up, but killing threads is no\n necessarily reliable. This is turned off by default, since i"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "orker in self.workers:\n if not hasattr(worker, 'thread_id'):\n # Not initialized\n "..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "ent for killed thread %s' % thread_id)\n\n def thread_exists(self, thread_id):\n \"\"\"\n Returns true if a th"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> " zombie threads is more than %s limit',\n len(found), self.max_zombie_threads_before_die)\n self"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "\n worker.join(0.5)\n if worker.isAlive():\n hung_workers.append(worker)\n zombi"..., 4096) = 4096
24075 mprotect(0x7f3350021000, 180224, PROT_READ|PROT_WRITE <unfinished ...>
24075 <... mprotect resumed> ) = 0
24075 mprotect(0x7f335004d000, 8192, PROT_READ|PROT_WRITE <unfinished ...>
24075 <... mprotect resumed> ) = 0
24075 read(3, "lf.running = True\n assert nworkers > 0, \"ThreadPoolMixIn servers must have at least one worker\"\n self.thre"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "_size=request_queue_size)\n if threadpool_options is None:\n threadpool_options = {}\n ThreadPoolM"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "tpserver.ThreadPool for specific\n options (threadpool_workers is a specific option that can\n also go h"..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "orker thread will process\n before dying (and replacing itself with a new worker thread).\n Default 100.\n\n "..., 4096) = 2414
24075 read(3, "", 4096) = 0
24075 close(3 <unfinished ...>
24075 <... close resumed> ) = 0
24075 munmap(0x7f33908e6000, 4096 <unfinished ...>
24075 <... munmap resumed> ) = 0
24075 stat("/usr/lib/python2.6/site-packages/paste/script/serve.py", <unfinished ...>
24075 <... stat resumed> {st_mode=S_IFREG|0644, st_size=22630, ...}) = 0
24075 open("/usr/lib/python2.6/site-packages/paste/script/serve.py", O_RDONLY <unfinished ...>
24075 <... open resumed> ) = 3
24075 fstat(3, <unfinished ...>
24075 <... fstat resumed> {st_mode=S_IFREG|0644, st_size=22630, ...}) = 0
24075 fstat(3, <unfinished ...>
24075 <... fstat resumed> {st_mode=S_IFREG|0644, st_size=22630, ...}) = 0
24075 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
24075 <... mmap resumed> ) = 0x7f33908e6000
24075 read(3, <unfinished ...>
24075 <... read resumed> "# (c) 2005 Ian Bicking and contributors; written for Paste (http://pythonpaste.org)\n# Licensed under the MIT license: ht"..., 8192) = 8192
24075 read(3, <unfinished ...>
24075 <... read resumed> "ame = self.options.app_name\n vars = self.parse_vars(restvars)\n if not self._scheme_re.search(app_spec):\n "..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> "\n print 'Entering daemon mode'\n pid = os.fork()\n if pid:\n # The forked process also "..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> " print '^C caught in monitor process'\n if self.verbose > 1:\n raise\n "..., 4096) = 4096
24075 read(3, <unfinished ...>
24075 <... read resumed> " f.close()\n try:\n pid_in_file = int(content)\n except ValueError:\n pass\n else:\n if pid_in_f"..., 4096) = 2150
24075 read(3, <unfinished ...>
24075 <... read resumed> "", 4096) = 0
24075 close(3 <unfinished ...>
24075 <... close resumed> ) = 0
24075 munmap(0x7f33908e6000, 4096 <unfinished ...>
24075 <... munmap resumed> ) = 0
24075 write(23, "Exception in thread worker 4:\nTraceback (most recent call last):\n File \"/usr/lib64/python2.6/threading.py\", line 532, i"..., 560 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 close(24 <unfinished ...>
24075 <... close resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(23, "Unhandled exception in thread started by ", 41 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(2, "Unhandled exception in thread started by ", 41 <unfinished ...>
24075 <... write resumed> ) = 41
24075 write(23, "<bound method Thread.__bootstrap of <Thread(worker 4, stopped 139858647488256)>>", 80 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(23, "\n", 1 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 write(2, "\n", 1 <unfinished ...>
24075 <... write resumed> ) = 1
24075 write(23, "Traceback (most recent call last):\n", 35 <unfinished ...>
24075 <... write resumed> ) = -1 EBADF (Bad file descriptor)
24075 close(14) = -1 EBADF (Bad file descriptor)
24075 exit_group(0) = ?

</pre>

TagsNo tags attached.

Activities

ludovic

ludovic

2015-05-25 19:52

administrator   ~0008534

Retry with v2.3. Reopen if necessary.

Issue History

Date Modified Username Field Change
2012-08-13 19:45 jraby New Issue
2012-10-03 15:11 wsourdeau Project SOGo Native Outlook Compatibility (obsolete) => SOGo
2012-10-03 15:12 wsourdeau Category => OpenChange backend
2015-05-25 19:52 ludovic Note Added: 0008534
2015-05-25 19:52 ludovic Status new => resolved
2015-05-25 19:52 ludovic Resolution open => suspended
2015-05-25 19:52 ludovic Assigned To => ludovic