Bug 42507 - Traceback when reading pickle files
Traceback when reading pickle files
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: AD Connector
UCS 4.1
Other Linux
: P5 normal (vote)
: UCS 4.1-4-errata
Assigned To: Florian Best
Stefan Gohmann
:
Depends on:
Blocks: 43235
  Show dependency treegraph
 
Reported: 2016-09-26 16:35 CEST by Nico Stöckigt
Modified: 2017-01-05 11:22 CET (History)
5 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 2: Will only affect a few installed domains
How will those affected feel about the bug?: 5: Blocking further progress on the daily work
User Pain: 0.286
Enterprise Customer affected?: Yes
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number: 2016090921000131, 2016101221000292
Bug group (optional):
Max CVSS v3 score:


Attachments
bug_42507.patch (1.29 KB, patch)
2016-09-28 12:54 CEST, Arvid Requate
Details | Diff
patch (1.78 KB, patch)
2016-09-29 15:33 CEST, Florian Best
Details | Diff
check-files.py (1.84 KB, text/x-python)
2016-10-13 10:15 CEST, Stefan Gohmann
Details
patch (1.88 KB, patch)
2016-12-20 12:04 CET, Florian Best
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Nico Stöckigt univentionstaff 2016-09-26 16:35:22 CEST
Bei einem begleiteten Benutzerimport fiel folgender Traceback im 'connector-status.log' auf.


 --- connect failed, failure was: ---

Traceback (most recent call last):
  File "/usr/share/pyshared/univention/connector/ad/main.py", line 290, in main
    connect()
  File "/usr/share/pyshared/univention/connector/ad/main.py", line 234, in connect
    change_counter=ad.poll_ucs()
  File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 911, in poll_ucs
    self._generate_dn_list_from(files)
  File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 885, in _generate_dn_list_from
    dn,new,old,old_dn=cPickle.load(f)
ValueError: insecure string pickle


folgende Pakete sind installiert:
 python-univention-connector      10.0.2-9.509.201609131411
 python-univention-connector-ad   10.0.2-9.509.201609131411
 univention-ad-connector          10.0.2-9.509.201609131411
Comment 1 Nico Stöckigt univentionstaff 2016-09-26 16:40:47 CEST
The behavior seems at first to have no adverse effects. A simple try-finally with a file closing statement should easily fix this.


885   dn,new,old,old_dn=cPickle.load(f)
886   if not self.dn_list.get(dn):
887      self.dn_list[dn]=[filename]
888   else:
889      self.dn_list[dn].append(filename)
890
Comment 2 Florian Best univentionstaff 2016-09-26 16:44:29 CEST
What is a "begleiteten Benutzerimport"?
How does it come that the pickle file is corrupt / who created the corrupt pickle file?
Is it reproducible? How?
Comment 3 Florian Best univentionstaff 2016-09-26 16:59:46 CEST
>>> cPickle.loads("Sfoo\np1\n.")
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
ValueError: insecure string pickle
Comment 4 Florian Best univentionstaff 2016-09-26 17:02:27 CEST
I think that this is a race condition, not sure. The pickle file is read while it is not completely written to disk?
Comment 5 Arvid Requate univentionstaff 2016-09-26 19:39:29 CEST
Hmm, strange, exactly starting with that version (10.0.2-9) the pickle files written by the ad-connector.py listener module are explicitly checked by the module ( via function _dump_changes_to_file_and_check_file ) against corruption. That code has originally been created for the s4-connector.py listener module to address issues of broken pickle files (Bug 29625 and refactored for Bug 24273).
Comment 6 Florian Best univentionstaff 2016-09-26 20:18:24 CEST
How does it come that this package version was build 2016 but the 2 referenced bugs are from 2012/2013?
Comment 7 Arvid Requate univentionstaff 2016-09-26 20:20:22 CEST
Because the fix for the s4-connector has only been merged "later".
Comment 8 Florian Best univentionstaff 2016-09-27 12:04:16 CEST
(In reply to Arvid Requate from comment #7)
> Because the fix for the s4-connector has only been merged "later".

So you mean Bug #41938 aka svn r72543
Comment 9 Nico Stöckigt univentionstaff 2016-09-28 09:16:50 CEST
(In reply to Florian Best from comment #2)
> What is a "begleiteten Benutzerimport"?
> How does it come that the pickle file is corrupt / who created the corrupt
> pickle file?
> Is it reproducible? How?

That means, that I was monitoring an multi Users Import as I noticed this traceback in the connector-status.log, which is normally truncated so the traceback won't never be seen.

To reproduce the behavior it's needed to monitor or record the status.log - the debug-level was set to 4, I don't know if this will have any impact to the status.log.
Comment 10 Stefan Gohmann univentionstaff 2016-09-28 10:10:58 CEST
I guess the write of the pickle files is not a atomic process, so they might be incomplete. Do we see any consequences of this error message?
Comment 11 Arvid Requate univentionstaff 2016-09-28 12:54:26 CEST
Created attachment 8042 [details]
bug_42507.patch

The ad-connector.py listener doesn't create the files atomically, so I guess it could happen, that the AD-Connector reads a file that is in the process of creation. The attached patch may be an idea to change that.

If this is fixed in the AD-Connector, this bug should be cloned to get fixed in the S4-Connector too.
Comment 12 Florian Best univentionstaff 2016-09-29 15:33:12 CEST
Created attachment 8054 [details]
patch

Good idea Arvid!
I adapted the patch to use shutil.move (which would support the "tmp" directory to be on a own partition - even if it's only a subdirectory) and use "with open()".
Comment 13 Christina Scheinig univentionstaff 2016-10-13 09:50:07 CEST
Happened again on UCS version 4.1-3 Errata 291

Wed Oct 12 16:20:37 2016
 --- connect failed, failure was: ---

Traceback (most recent call last):
  File "/usr/share/pyshared/univention/connector/ad/main.py", line 290, in main
    connect()
  File "/usr/share/pyshared/univention/connector/ad/main.py", line 199, in connect
    ad.initialize_ucs()
  File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 822, in initialize_ucs
    self.poll_ucs()
  File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 911, in poll_ucs
    self._generate_dn_list_from(files)
  File "/usr/lib/pymodules/python2.7/univention/connector/__init__.py", line 885, in _generate_dn_list_from
    dn,new,old,old_dn=cPickle.load(f)
EOFError
Comment 14 Stefan Gohmann univentionstaff 2016-10-13 10:15:26 CEST
Created attachment 8096 [details]
check-files.py

Attached you find a simple script which checks the pickle files in the directory /var/lib/univention-connector/ad/:

root@master161:~# ./check-files.py 
Please remove the following file(s):
  /var/lib/univention-connector/ad/.1473765297.412123.swp
  /var/lib/univention-connector/ad/1473765297.412123

root@master162:~# ./check-files.py 
Scanned 12 files successfully
root@master162:~#
Comment 15 Stefan Gohmann univentionstaff 2016-12-14 13:25:35 CET
(In reply to Florian Best from comment #12)
> Created attachment 8054 [details]
> patch

Can you add a patch without cleanups?
Comment 16 Florian Best univentionstaff 2016-12-20 12:04:35 CET
Created attachment 8311 [details]
patch

(In reply to Stefan Gohmann from comment #15)
> (In reply to Florian Best from comment #12)
> > Created attachment 8054 [details]
> > patch
> 
> Can you add a patch without cleanups?

There hasn't been very much cleanup except the imports which are already fixed now and the 2 times with-open construct. The patch basically is nearly the same length :/
Comment 17 Stefan Gohmann univentionstaff 2016-12-20 21:53:36 CET
(In reply to Florian Best from comment #16)
> Created attachment 8311 [details]
> patch

Thanks, looks good. Please apply.
Comment 18 Florian Best univentionstaff 2016-12-21 10:13:06 CET
Applied that patch.

univention-ad-connector (10.0.2-19):
r75462 | Bug #42507: Fix race condition between writing and reading pickle files

univention-ad-connector.yaml:
r75463 | YAML Bug #42507
Comment 19 Florian Best univentionstaff 2016-12-22 11:53:54 CET
Missing merge to UCS 4.2:

univention-ad-connector (11.0.5-9):
r75500 | Bug #42507: Fix race condition between writing and reading pickle files
Comment 20 Florian Best univentionstaff 2016-12-22 13:16:13 CET
I added also the commit r75503 from Bug #43235 to keep AD connector and S4 connector code in sync. The removed code block would still work in AD Connector but it also doesn't make sense here.

univention-ad-connector (10.0.2-20):
r75508 | Bug #42507: code cleanup
Comment 21 Stefan Gohmann univentionstaff 2017-01-04 16:45:17 CET
Tests: OK

Code review: OK

UCS Test: OK

UCS 4.2 merge: OK

YAML: OK
Comment 22 Janek Walkenhorst univentionstaff 2017-01-05 11:22:40 CET
<http://errata.software-univention.de/ucs/4.1/370.html>