bugGNU Parallel - Bugs: bug #40733, Different output, depending on...

 
 

bug #40733: Different output, depending on value of -j parameter

Submitter:  None
Submitted:  Thu 28 Nov 2013 10:37:15 AM UTC
   
 
Category:  None Severity:  3 - Normal
Item Group:  None Status:  Invalid
Privacy:  Public Assigned to:  tange
Open/Closed:  Closed
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Mon 02 Dec 2013 10:52:51 AM UTC, comment #14: 
Ole Tange <tange>
Group administrator
Mon 02 Dec 2013 10:37:17 AM UTC, comment #13: 

Good idea, I'll sign up for the list to discuss further.

Have been gently promoting it both at work and elsewhere already...

https://twitter.com/andrew_clegg/status/396983762149715968

Will look for more opportunities :-)

Anonymous
Sun 01 Dec 2013 12:05:43 PM UTC, comment #12: 

Could you try the new --compress option?

It will compress the tmp files, and if the disk runs full, the compressor will complain.


Ole Tange <tange>
Group administrator
Sat 30 Nov 2013 11:24:50 PM UTC, comment #11: 


> 1. Forwarding stderr from the jobs to the stderr of the parallel process itself, so the user can see for example if one or more of the jobs results in "no space left on device".


stderr is sent to stderr. Do see this in action try:

    parallel ls ::: no_such_file >/dev/null

The problem here is that stdout and stderr are both saved to the same $TMPDIR, so if $TMPDIR runs full, the the error message can of course also not be saved in $TMPDIR. So you will never be able to get the information from zcat.

Let's discuss how this can be mitigated on the mailing list.

> 2. Sending the output of --debug to stderr rather than stdout.


This is the first situation where this has caused problems. If I see more bugs where this is an issue, I may change it.

> Thanks for all your help with this. And good work -- parallel is an excellent tool!


Thanks. If you like GNU Parallel:

  • Give a demo at your local user group/team/colleagues
  • Post the intro videos on Reddit/Diaspora*/forums/blogs/

Identi.ca/Google+/Twitter/Facebook/Linkedin/mailing lists

  • Request or write a review for your favourite blog or magazine
  • Invite me for your next conference


If you use GNU Parallel for research:

  • Please cite GNU Parallel in your publications (use --bibtex)


If GNU Parallel saves you money:


Ole Tange <tange>
Group administrator
Sat 30 Nov 2013 02:43:52 PM UTC, comment #10: 

Aha, figured it out.

The differences in the output size in my last comment were due to the --debug output getting mixed in with the zcat output.

Without --debug, and with a sensible --tmpdir, the number of lines in the output files exactly matches the number of lines I get when expanding and counting the files in serial.

So this is not a bug, but arguably a case of poor error reporting.

I would suggest:

1. Forwarding stderr from the jobs to the stderr of the parallel process itself, so the user can see for example if one or more of the jobs results in "no space left on device".

As far as I can tell, this wasn't reported or logged anywhere. Sending it to stderr by default might reduce spurious bug reports :-)

2. Sending the output of --debug to stderr rather than stdout.

Thanks for all your help with this. And good work -- parallel is an excellent tool!


Anonymous
Sat 30 Nov 2013 01:52:47 PM UTC, comment #9: 

A couple of notes while I look for somewhere to host the files:

1. Not sure about "I have a feeling it is a problem on your local system" when I've tried it on two separate servers with different OS versions, different hardware config and different versions of parallel :-)

2. --debug produced no output at all.

3. When I provided a different --tmpdir the command produced output with a very similar number of lines to the input data, but not exactly the same.

[davteam@lo3uppaldbs001 parallel_bug_data]$ zcat *.gz|wc -l
104076014
[davteam@lo3uppaldbs001 parallel_bug_data]$ wc -l *.txt
  104076373 test4.txt
  104076369 test8.txt

test4.txt and test8.txt were generated using the exact same command as I posted yesterday, but with the addition of --tmpdir=<a disk with 3TB free> and --debug.

I'll try to reproduce it using one of the vbox VMs and put it somewhere you can download, all data included -- but this probably won't be until next week.



Anonymous
Sat 30 Nov 2013 12:54:59 PM UTC, comment #8: 

That's weird about box, sorry. I'll try it with a different temp dir, if that doesn't work I'll try to find a new location to host them.

Anonymous
Fri 29 Nov 2013 07:53:51 PM UTC, comment #7: 

Box.com fails after downloading 90% of each file.

Can you put the files a place were I can use wget to download the files?

Ole Tange <tange>
Group administrator
Fri 29 Nov 2013 06:22:11 PM UTC, comment #6: 

Are you running out of disk space in $TMPDIR (default: /tmp)?

You need space to buffer the uncompressed output of the concurrent zcats.

Ole Tange <tange>
Group administrator
Fri 29 Nov 2013 06:05:49 PM UTC, comment #5: 

I have a feeling it is a problem on your local system.

I do not have access to a RHEL system. See if you can reproduce the error on one of the VirtualBox images:
http://sourceforge.net/projects/virtualboximage/files/

Debugging is enabled with --debug.

Ole Tange <tange>
Group administrator
Fri 29 Nov 2013 05:03:15 PM UTC, comment #4: 

Okay, I've randomised all the data in the logfiles, and uploaded them here:

https://pearson.box.com/s/mpiqw0w7yqa94vddbg1z

It's rather a lot of data, but I think that's a factor, as I couldn't reproduce the problem with toy examples.

Compare the output of these two commands:

ls 2013-05-04*gz | parallel --gnu -j 8 zcat > test8.txt
ls 2013-05-04*gz | parallel --gnu -j 4 zcat > test4.txt

The two output files are very different sizes.

I've tested this with parallel 20131022 on RHEL 6.4, and also 20130522 on 6.2.

Anonymous
Fri 29 Nov 2013 12:43:17 PM UTC, comment #3: 

I'll attempt to replace the data in the log files with random junk, while retaining the structure. Hopefully that will make it reproducible without requiring access to commercially-sensitive and personally-identifying data.

While I'm working on that -- is there any way parallel can produce debug or trace-level logging of what it's actually doing?

Anonymous
Thu 28 Nov 2013 02:59:21 PM UTC, comment #2: 

Without access to data that can reproduce the error on other systems it is next to impossible to fix this bug.

Please provide such data within a month.

After a month the bug will be closed. You should feel free to re-open it when you have data that can reproduce the error.


Ole Tange <tange>
Group administrator
Thu 28 Nov 2013 02:12:36 PM UTC, comment #1: 

I've also discovered that the output when using the --files parameter varies for different values of -j, but in the opposite direction -- i.e. you get more output with higher values of -j. In the original post, without --files, I was getting less output with higher values of -j.

e.g. with -j 8 there are 8 files in the output with no data in. With -j 4 it's 9 empty files, but with -j 16 I only see one empty file.

However, some files are apparently also getting truncated. I see output files with only 3 or 4 MB of data, even though the smallest input file is a 17 MB gz.

None of these files are corrupt in any way, as far as I can tell -- I can zcat them all in series without errors.

Transcript follows:

[davteam@lo3uppaldbs001 05]$ ls 2013-05-04*gz | /home/aclegan/parallel_bug/parallel-20131022/src/parallel --gnu -j 8 --files zcat
/tmp/kLp0hnDpsd.par
/tmp/4TKjM2RqZK.par
/tmp/BodmH02YeZ.par
/tmp/VAOc8oUrLP.par
/tmp/ScsfqFToHa.par
/tmp/Me1gpQZdsn.par
/tmp/7cM7_uW8wS.par
/tmp/zGpgwmys1s.par
/tmp/73F32Y4u5i.par
/tmp/tYAV0XnkZ0.par
/tmp/Jza8m2pl_I.par
/tmp/vmoDJswisB.par
/tmp/Oj92SNtoxR.par
/tmp/g1OnRaTbrO.par
/tmp/kUA7qnb1B4.par
/tmp/ajJjU_36yg.par
/tmp/zYs9uDRIlo.par
/tmp/24luyqRlWm.par
/tmp/_vaOguQQxL.par
/tmp/YYBE3p3xNt.par
/tmp/EC9tipxMWC.par
/tmp/w4IZmkgUfC.par
/tmp/wjwyAZBrdf.par
/tmp/wA3GuT2C1Q.par
[davteam@lo3uppaldbs001 05]$ ls -lh /tmp/*.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/24luyqRlWm.par
-rw------- 1 davteam davteam 112M Nov 28 13:59 /tmp/4TKjM2RqZK.par
-rw------- 1 davteam davteam 387M Nov 28 13:59 /tmp/73F32Y4u5i.par
-rw------- 1 davteam davteam 241M Nov 28 13:59 /tmp/7cM7_uW8wS.par
-rw------- 1 davteam davteam 237M Nov 28 13:59 /tmp/ajJjU_36yg.par
-rw------- 1 davteam davteam 126M Nov 28 13:59 /tmp/BodmH02YeZ.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/EC9tipxMWC.par
-rw------- 1 davteam davteam 338M Nov 28 13:59 /tmp/g1OnRaTbrO.par
-rw------- 1 davteam davteam 253M Nov 28 13:59 /tmp/Jza8m2pl_I.par
-rw------- 1 davteam davteam 106M Nov 28 13:59 /tmp/kLp0hnDpsd.par
-rw------- 1 davteam davteam 224M Nov 28 13:59 /tmp/kUA7qnb1B4.par
-rw------- 1 davteam davteam 208M Nov 28 13:59 /tmp/Me1gpQZdsn.par
-rw------- 1 davteam davteam 394M Nov 28 13:59 /tmp/Oj92SNtoxR.par
-rw------- 1 davteam davteam 150M Nov 28 13:59 /tmp/ScsfqFToHa.par
-rw------- 1 davteam davteam 148M Nov 28 13:59 /tmp/tYAV0XnkZ0.par
-rw------- 1 davteam davteam 126M Nov 28 13:59 /tmp/VAOc8oUrLP.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/_vaOguQQxL.par
-rw------- 1 davteam davteam 308M Nov 28 13:59 /tmp/vmoDJswisB.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/w4IZmkgUfC.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/wA3GuT2C1Q.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/wjwyAZBrdf.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/YYBE3p3xNt.par
-rw------- 1 davteam davteam 309M Nov 28 13:59 /tmp/zGpgwmys1s.par
-rw------- 1 davteam davteam    0 Nov 28 13:59 /tmp/zYs9uDRIlo.par
[davteam@lo3uppaldbs001 05]$ rm /tmp/*.par
[davteam@lo3uppaldbs001 05]$ ls 2013-05-04*gz | /home/aclegan/parallel_bug/parallel-20131022/src/parallel --gnu -j 4 --files zcat
/tmp/cM_6zL1Ms7.par
/tmp/woRIrBThVF.par
/tmp/2uOdYs_FVO.par
/tmp/lxETXD0_Si.par
/tmp/9PgNhFvRp4.par
/tmp/b6pdLFLg5u.par
/tmp/_5jtbxYyUi.par
/tmp/6qvM8zZuzD.par
/tmp/lsJvgUFvqB.par
/tmp/2C313xgnY9.par
/tmp/uEkIkjCOuz.par
/tmp/eVylY3I7h5.par
/tmp/eNcqDcUPaT.par
/tmp/hQ7QwwZraD.par
/tmp/gW6vgxteKW.par
/tmp/tzMdQ2P1kD.par
/tmp/KyFrXr6qqU.par
/tmp/6vkPlh3cTz.par
/tmp/BvwOAbkUxc.par
/tmp/rXxCnVCMTx.par
/tmp/E4VItctJaX.par
/tmp/l37HaIDp3b.par
/tmp/wnEgoBWLRK.par
/tmp/T5gtZL4sCh.par
[davteam@lo3uppaldbs001 05]$ ls -lh /tmp/*.par
-rw------- 1 davteam davteam 612M Nov 28 14:00 /tmp/2C313xgnY9.par
-rw------- 1 davteam davteam 208M Nov 28 14:00 /tmp/2uOdYs_FVO.par
-rw------- 1 davteam davteam 126M Nov 28 14:00 /tmp/_5jtbxYyUi.par
-rw------- 1 davteam davteam 241M Nov 28 14:00 /tmp/6qvM8zZuzD.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/6vkPlh3cTz.par
-rw------- 1 davteam davteam 106M Nov 28 14:00 /tmp/9PgNhFvRp4.par
-rw------- 1 davteam davteam 309M Nov 28 14:00 /tmp/b6pdLFLg5u.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/BvwOAbkUxc.par
-rw------- 1 davteam davteam 126M Nov 28 14:00 /tmp/cM_6zL1Ms7.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/E4VItctJaX.par
-rw------- 1 davteam davteam 174M Nov 28 14:00 /tmp/eNcqDcUPaT.par
-rw------- 1 davteam davteam 418M Nov 28 14:00 /tmp/eVylY3I7h5.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/gW6vgxteKW.par
-rw------- 1 davteam davteam 4.0M Nov 28 14:00 /tmp/hQ7QwwZraD.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/KyFrXr6qqU.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/l37HaIDp3b.par
-rw------- 1 davteam davteam 432M Nov 28 14:00 /tmp/lsJvgUFvqB.par
-rw------- 1 davteam davteam 112M Nov 28 14:00 /tmp/lxETXD0_Si.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/rXxCnVCMTx.par
-rw------- 1 davteam davteam 4.3M Nov 28 14:00 /tmp/T5gtZL4sCh.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/tzMdQ2P1kD.par
-rw------- 1 davteam davteam 649M Nov 28 14:00 /tmp/uEkIkjCOuz.par
-rw------- 1 davteam davteam    0 Nov 28 14:00 /tmp/wnEgoBWLRK.par
-rw------- 1 davteam davteam 150M Nov 28 14:00 /tmp/woRIrBThVF.par
[davteam@lo3uppaldbs001 05]$ rm /tmp/*.par
[davteam@lo3uppaldbs001 05]$ ls 2013-05-04*gz | /home/aclegan/parallel_bug/parallel-20131022/src/parallel --gnu -j 16 --files zcat
/tmp/f2YtUL4y68.par
/tmp/AcBYsTarj9.par
/tmp/NkWOO20tcb.par
/tmp/rRdPOgWJy6.par
/tmp/tFd_eX0qZl.par
/tmp/YFJlLR1Q2V.par
/tmp/3LApJWve5n.par
/tmp/P7VfJOMBPO.par
/tmp/ZLzovvWP1U.par
/tmp/23bf8QXQZY.par
/tmp/XCmbwqmPoN.par
/tmp/ilKvw_hh9d.par
/tmp/XvmjFabNSP.par
/tmp/ZPey7MwYEE.par
/tmp/bmZ4abaf2e.par
/tmp/2iuaw2IWDE.par
/tmp/zOx07tKd64.par
/tmp/ouorbFLRoH.par
/tmp/DC6W5AS0JT.par
/tmp/nzhcc6spM3.par
/tmp/Ijww9nqwr_.par
/tmp/K5WakZpOY9.par
/tmp/qP1wNu6AAB.par
/tmp/WY0jIpSmZV.par
[davteam@lo3uppaldbs001 05]$ ls -lh /tmp/*.par
-rw------- 1 davteam davteam 267M Nov 28 14:01 /tmp/23bf8QXQZY.par
-rw------- 1 davteam davteam 220M Nov 28 14:01 /tmp/2iuaw2IWDE.par
-rw------- 1 davteam davteam 241M Nov 28 14:01 /tmp/3LApJWve5n.par
-rw------- 1 davteam davteam 106M Nov 28 14:01 /tmp/AcBYsTarj9.par
-rw------- 1 davteam davteam 222M Nov 28 14:01 /tmp/bmZ4abaf2e.par
-rw------- 1 davteam davteam  30M Nov 28 14:01 /tmp/DC6W5AS0JT.par
-rw------- 1 davteam davteam 112M Nov 28 14:01 /tmp/f2YtUL4y68.par
-rw------- 1 davteam davteam 111M Nov 28 14:01 /tmp/Ijww9nqwr_.par
-rw------- 1 davteam davteam 141M Nov 28 14:01 /tmp/ilKvw_hh9d.par
-rw------- 1 davteam davteam 108M Nov 28 14:01 /tmp/K5WakZpOY9.par
-rw------- 1 davteam davteam 126M Nov 28 14:01 /tmp/NkWOO20tcb.par
-rw------- 1 davteam davteam    0 Nov 28 14:01 /tmp/nzhcc6spM3.par
-rw------- 1 davteam davteam  76M Nov 28 14:01 /tmp/ouorbFLRoH.par
-rw------- 1 davteam davteam 274M Nov 28 14:01 /tmp/P7VfJOMBPO.par
-rw------- 1 davteam davteam  82M Nov 28 14:01 /tmp/qP1wNu6AAB.par
-rw------- 1 davteam davteam 126M Nov 28 14:01 /tmp/rRdPOgWJy6.par
-rw------- 1 davteam davteam 150M Nov 28 14:01 /tmp/tFd_eX0qZl.par
-rw------- 1 davteam davteam 3.7M Nov 28 14:01 /tmp/WY0jIpSmZV.par
-rw------- 1 davteam davteam 207M Nov 28 14:01 /tmp/XCmbwqmPoN.par
-rw------- 1 davteam davteam 218M Nov 28 14:01 /tmp/XvmjFabNSP.par
-rw------- 1 davteam davteam 208M Nov 28 14:01 /tmp/YFJlLR1Q2V.par
-rw------- 1 davteam davteam 272M Nov 28 14:01 /tmp/ZLzovvWP1U.par
-rw------- 1 davteam davteam 166M Nov 28 14:01 /tmp/zOx07tKd64.par
-rw------- 1 davteam davteam 206M Nov 28 14:01 /tmp/ZPey7MwYEE.par
[davteam@lo3uppaldbs001 05]$ rm /tmp/*.par

Anonymous
Thu 28 Nov 2013 10:37:15 AM UTC, original submission:  

The manual states:


GNU parallel makes sure output from the commands is the same output as you would get had you run the commands sequentially. This makes it possible to use output from GNU parallel as input for other programs.


However this doesn't seem to be the case.

I am using parallel to process gzipped log files.

The output I see depends on the number of jobs I specify in the -j parameter.

Example -- copy and pasted from terminal:


[davteam@lo3uppaldbs001 05]$ ls 2013-05-04*gz | /home/aclegan/parallel_bug/parallel-20131022/src/parallel --gnu -j 8 zcat > test8.txt
[davteam@lo3uppaldbs001 05]$ wc -l test8.txt
37327858 test8.txt
[davteam@lo3uppaldbs001 05]$ ls 2013-05-04*gz | /home/aclegan/parallel_bug/parallel-20131022/src/parallel --gnu -j 4 zcat > test4.txt
[davteam@lo3uppaldbs001 05]$ wc -l test4.txt
52038007 test4.txt


These are archives -- the files are not changing.

I can't easily share the files, as they contain personally identifying information. I've tried to reproduce this with synthetic test data, but I can't.

The files are not huge -- between ~ 10 to 150 MB each.

I have checked using the --dry-run parameter, and the output looks identical each time:


zcat 2013-05-04-00.gz
zcat 2013-05-04-01.gz
zcat 2013-05-04-02.gz
zcat 2013-05-04-03.gz
zcat 2013-05-04-04.gz
zcat 2013-05-04-05.gz
zcat 2013-05-04-06.gz
zcat 2013-05-04-07.gz
zcat 2013-05-04-08.gz
zcat 2013-05-04-09.gz
zcat 2013-05-04-10.gz
zcat 2013-05-04-11.gz
zcat 2013-05-04-12.gz
zcat 2013-05-04-13.gz
zcat 2013-05-04-14.gz
zcat 2013-05-04-15.gz
zcat 2013-05-04-16.gz
zcat 2013-05-04-17.gz
zcat 2013-05-04-18.gz
zcat 2013-05-04-19.gz
zcat 2013-05-04-20.gz
zcat 2013-05-04-21.gz
zcat 2013-05-04-22.gz
zcat 2013-05-04-23.gz


These are hourly log rotations over the course of one day.

Additional note:

I used the following commands to check which hours were present in the output files:


[davteam@lo3uppaldbs001 05]$ cut -c 1-13 test4.txt|sort -u

and

[davteam@lo3uppaldbs001 05]$ cut -c 1-13 test8.txt|sort -u


The output in both cases showed that every hours was represented:


2013-05-03      23
2013-05-04      00
2013-05-04      01
2013-05-04      02
2013-05-04      03
2013-05-04      04
2013-05-04      05
2013-05-04      06
2013-05-04      07
2013-05-04      08
2013-05-04      09
2013-05-04      10
2013-05-04      11
2013-05-04      12
2013-05-04      13
2013-05-04      14
2013-05-04      15
2013-05-04      16
2013-05-04      17
2013-05-04      18
2013-05-04      19
2013-05-04      20
2013-05-04      21
2013-05-04      22
2013-05-04      23


(plus a few from the previous date which happens due to a lag in our log processing pipeline)

So each file is getting at least partially processed by zcat in my parallel command.


Anonymous

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by tange (Posted a comment)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only logged-in users can vote.

     

    Follow 4 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2013-11-30 tange StatusNeed Info Invalid
        Assigned toNone tange
        Open/ClosedOpen Closed
    2013-11-28 tange StatusNone Need Info

    Back to the top

    Powered by Savane 3.13-bb6a.
    Corresponding source code