Race condition causing only the content in the latest of concurrent commits to be visible

[GoogleCodeExporter]

I found this while migrating a lot of photos to a BOAR repo. Good thing I paid 
attention.

What steps will reproduce the problem?

1. Do a long import into the repository. Mine was on a local USB hard disk 

S:\pix\years>boar --repo=L:\boarrepo\pixrepo import S:\pix\years\2004 
pix/years/2004
Looking for files: 1001
Verifying checksum cache: 1001
Scanning: 502 files and 799 Mb remaining (64.9% complete, 1.9 Mb/s)

2. Then do updates in a previously updated local repo working dir ( I used two, 
one each on  drive C and L )

3. Now copy some new files in and view status. Note they are scheduled to be 
added.

C:\Users\David\Pictures\boar\pix\years>boar status
Looking for files: 14074
Verifying checksum cache: 14074
Scanning: 0 files and 0 Mb remaining (100.0% complete, 26.6 Mb/s)
Loading session... done
Calculating changes... done
A ingest/Mobile Photos/.picasa.ini
A ingest/Mobile Photos/381A0007.jpg
A ingest/Mobile Photos/381A0008.jpg
A ingest/Mobile Photos/DAC_20110530_142343.jpg
A ingest/Mobile Photos/DAC_20110611_202845.jpg
...
A ingest/Mobile Photos/IMG_20111230_153117.jpg
A ingest/Mobile Photos/IMG_20111231_161527.jpg
Finished in 7.39 seconds

4. Now copy MORE files in and commit more...

C:\Users\David\Pictures\boar\pix\years>boar ci
Looking for files: 14072
Verifying checksum cache: 14072
Loading session... done
Calculating changes... done
Sending ingest/Mobile Photos/.picasa.ini
Sending ingest/Mobile Photos/381A0007.jpg
Sending ingest/Mobile Photos/381A0008.jpg
Sending ingest/Mobile Photos/DAC_20110530_142343.jpg
Sending ingest/Mobile Photos/DAC_20110611_202845.jpg
Sending ingest/Mobile Photos/DAC_20110703_181828.jpg
...
Sending ingest/Mobile Photos/IMG_20111230_145426.jpg
Sending ingest/Mobile Photos/IMG_20111230_153117.jpg
Sending ingest/Mobile Photos/IMG_20111231_161527.jpg
Deleting pix-to-sort/hero/IMAG0004.jpg
Deleting pix-to-sort/hero/IMAG0005.jpg
Checked in session id 32
Finished in 5.87 seconds


5. Copy in some more files and commit

C:\Users\David\Pictures\boar\pix\years>boar ci
Looking for files: 14089
Verifying checksum cache: 14089
Scanning: 0 files and 0 Mb remaining (100.0% complete, 1.9 Mb/s)
Loading session... done
Calculating changes... done
Sending ingest/100SSMED-cameraphone/.picasa.ini
Sending ingest/100SSMED-cameraphone/SSPX0008.JPG
Sending ingest/100SSMED-cameraphone/SSPX0009.JPG
...
Sending ingest/100SSMED-cameraphone/SSPX0029.JPG
Sending ingest/100SSMED-cameraphone/SSPX0030.JPG
Checked in session id 33
Finished in 5.81 seconds

6. update and verify the session id 33. All is well..

C:\Users\David\Pictures\boar\pix\years>boar update
Looking for files: 14089
Verifying checksum cache: 14089
Loading session... done
Calculating changes... done
Workdir now at revision 33
Finished in 7.72 seconds

7. Allow the import to complete

8. Now update the local working dir to pull in the newly imported items.

C:\Users\David\Pictures\boar\pix\years>boar update
Looking for files: 14089
Verifying checksum cache: 14089
Loading session... done
Calculating changes... done
<<<IMPORTED ITEMS>>>
Updating: pix-to-sort/hero/IMAG0004.jpg
Updating: pix-to-sort/hero/IMAG0005.jpg
Updating: years/2003/2003-Alex-PartyCHickFromBelgium/!checksums.md5
Updating: years/2003/2003-Alex-PartyCHickFromBelgium/.picasa.ini
Updating: years/2003/2003-Alex-PartyCHickFromBelgium/0082.JPG
Updating: years/2003/2003-Alex-PartyCHickFromBelgium/0089a.jpg
Updating: years/2003/storm/MVC-013S.JPG
Updating: years/2003/storm/MVC-014S.JPG
Updating: years/2003/storm/MVC-015S.JPG
Updating: years/2003/storm/MVC-016S.JPG
...
<<PREVIOUS CIs BEING DELETED>>
Deleted: ingest/100SSMED-cameraphone/SSPX0025.JPG
Deleted: ingest/100SSMED-cameraphone/SSPX0027.JPG
Deleted: ingest/100SSMED-cameraphone/SSPX0029.JPG
...
Deleted: ingest/100SSMED-cameraphone/SSPX0009.JPG
Deleted: ingest/100SSMED-cameraphone/SSPX0024.JPG
Deleted: ingest/100SSMED-cameraphone/SSPX0017.JPG
Deleted: ingest/Mobile Photos/IMG_20111213_130411.jpg
Deleted: ingest/Mobile Photos/IMG_20111124_155131.jpg
Deleted: ingest/Mobile Photos/.picasa.ini
Deleted: ingest/Mobile Photos/IMG_20111101_071441.jpg
...
Deleted: ingest/Mobile Photos/IMG_20111205_113358.jpg
Deleted: ingest/Mobile Photos/IMG_20111104_140902.jpg
Deleted: ingest/Mobile Photos/IMG_20111021_224211.jpg
Workdir now at revision 34
Finished in 162.95 seconds


What is the expected output? What do you see instead?

I expect to see all the imported items to be restored and the existing items to 
remain. Instead I just lost two commits worth of data - potentially more if I 
did more commits.

What platform are you using? (Windows XP, Windows 7, Linux, ...) Win7

What version of Python are you using? 2.7.2

What version of boar are you using? (Mercurial change id or daily build
date) Boar, version boar.16-Nov-2012

Please provide any additional information below.

If this cannot be fixed, an import should block any other commit operation 
using the mutex.

Original issue reported on code.google.com by david.ch...@gmail.com on 17 Feb 2014 at 7:17

[GoogleCodeExporter]

This is most certainly a bug. There is a mutex that is held while the session 
is being modified, but the problem is that the session is not locked until the 
actual commit starts. The list of files to commit are gathered before that 
happens, making your scenario possible. This will need fixing.

Original comment by ekb...@gmail.com on 17 Feb 2014 at 8:24

• Changed state: Accepted
• Added labels: Priority-High
• Removed labels: Priority-Medium

[GoogleCodeExporter]

I have pushed a temporary fix in changeset 094ecd048538 that aborts the 
long-running commit if there has been any intervening commits. Not too bad user 
experience, the scan has already been completed and you just need to do an 
update and then try again. 

Final solution will probably be to lock the session for the duration of the 
commit.

Original comment by ekb...@gmail.com on 17 Feb 2014 at 8:42

• Changed title: Race condition causing only the content in the latest of concurrent commits to be visible
• Changed state: Started