Can you post your csv file so we can actually run the program?
On Tuesday, April 7, 2015 at 6:21:18 AM UTC+2, Adam Labadorf wrote:
>
> Thanks for the replies. I took your suggestions (and reread the scope
> section of the docs) and am still experiencing the gc creep. Below is the
> complete program, with the notable changes that I wrapped the main
> computation in a function and eliminated all references to global variables
> inside. I'm also using the most recent nightly build of 0.4. Overall this
> version of the code is much faster, but there is still significant slowdown
> as the computation progresses. Is this expected? Do you see anything I'm
> doing wrong?
>
> # julia v0.4.0-dev+4159
> using HypothesisTests, ArrayViews
>
> type Result
> pvalue::Float64
> i::Int64
> j::Int64
> end
>
> function readtable(fn)
> fp = readcsv(fn)
> columns = fp[1,2:end]
> rows = fp[:,2:end]
> data = float(fp[2:end,2:end])
> return (columns,rows,data)
> end
> @time (cols, genes, counts) =
> readtable("../all_mRNA_nonzero_norm_counts_trim.csv")
>
> h_cols = find([c[1] == 'H' for c in cols])
> c_cols = find([c[1] == 'C' for c in cols])
>
> # filter out genes with zeros since it messes with the ratios
> nonzero = mapslices(x -> !any(x.==0),counts,2)
> counts = counts[find(nonzero),[h_cols;c_cols]]
>
> # slices seem to be faster
> h_cols = 1:length(h_cols)
> c_cols = (length(h_cols)+1):size(counts,2)
>
> # arrays are stored in column order, transpose counts to make
> # accessing more efficient
> counts = transpose(counts)
>
> genes = genes[find(nonzero)]
>
> function main(counts,genes,h_cols,c_cols)
>
> N = size(genes,1)
> M = size(counts,1)
>
> ratios = Array(Float64,M)
> function
> compute!(S::Array{Result,1},counts::Array{Float64,2},tot_i::Int64,i::Int64,j::Int64,h_cols::UnitRange{Int64},c_cols::UnitRange{Int64},M::Int64)
> for k=1:M
> ratios[k] = counts[k,i]/counts[k,j]
> end
> t = UnequalVarianceTTest(view(ratios,h_cols),view(ratios,c_cols))
> S[tot_i] = Result(pvalue(t),i,j)
> end
>
> tot_i = 0
> tot = (N^2-N)/2
>
> S = Array(Result,round(Int,tot))
>
> for i=1:N-1
> @time for j=(i+1):N
> tot_i += 1
> compute!(S,counts,tot_i,i,j,h_cols,c_cols,M)
> end
> end
>
> end
>
> S = main(counts,genes,h_cols,c_cols)
>
>
> And the output:
>
> elapsed time: 0.427719149 seconds (23 MB allocated, 39.90% gc time in 2
> pauses with 0 full sweep)
> elapsed time: 0.031006382 seconds (14 MB allocated)
> elapsed time: 0.131579099 seconds (14 MB allocated, 73.64% gc time in 1
> pauses with 1 full sweep)
> elapsed time: 0.140120717 seconds (14 MB allocated, 73.58% gc time in 1
> pauses with 0 full sweep)
> elapsed time: 0.030248237 seconds (14 MB allocated)
> ...
> elapsed time: 0.507894781 seconds (5 MB allocated, 97.65% gc time in 1
> pauses with 0 full sweep)
> elapsed time: 0.011821657 seconds (5 MB allocated)
> elapsed time: 0.011610651 seconds (5 MB allocated)
> elapsed time: 0.011816277 seconds (5 MB allocated)
> elapsed time: 0.50779098 seconds (5 MB allocated, 97.65% gc time in 1
> pauses with 0 full sweep)
> elapsed time: 0.011997168 seconds (5 MB allocated)
> elapsed time: 0.011721667 seconds (5 MB allocated)
> elapsed time: 0.011561071 seconds (5 MB allocated)
>
>
> On Saturday, April 4, 2015 at 12:38:46 PM UTC-4, Patrick O'Leary wrote:
>>
>> Silly me, ignoring all the commented out lines assuming they were
>> comments...yes, this is almost certainly it.
>>
>> On Saturday, April 4, 2015 at 3:24:50 AM UTC-5, Tim Holy wrote:
>>>
>>> Devectorization should never slow anything down. If it does, then you
>>> have
>>> some other problem. Here, M is a global variable, and that's probably
>>> what's
>>> killing you. Performance tip #1:
>>> http://docs.julialang.org/en/latest/manual/performance-tips/
>>>
>>> --Tim
>>>
>>> On Friday, April 03, 2015 09:43:51 AM Adam Labadorf wrote:
>>> > Hi,
>>> >
>>> > I am struggling with an issue related to garbage collection taking up
>>> the
>>> > vast majority (>99%) of compute time on a simple nested for loop. Code
>>> > excerpt below:
>>> >
>>> > # julia version 0.3.7
>>> > # counts is an MxN matrix of Float64
>>> > # N=15000
>>> > # M=108
>>> > # h_cols and c_cols are indices \in {1:M}
>>> > using HypothesisTests, ArrayViews
>>> > ratios = Array(Float64,M)
>>> > function compute!(S,tot_i::Int64,i::Int64,j::Int64)
>>> > ratios = view(counts,:,i)./view(counts,:,j)
>>> > #for k=1:M
>>> > # ratios[k] = counts[k,i]/counts[k,j]
>>> > #end
>>> > #ratios = counts[:,i]./counts[:,j]
>>> > t = UnequalVarianceTTest(ratios[h_cols],ratios[c_cols])
>>> > S[tot_i] = (pvalue(t),i,j)
>>> > end
>>> >
>>> > for i=1:N-1
>>> > @time for j=(i+1):N
>>> > tot_i += 1
>>> > compute!(S,tot_i,i,j)
>>> > end
>>> > end
>>> >
>>> > The loop begins fast, output from time:
>>> >
>>> > elapsed time: 1.023850054 seconds (62027220 bytes allocated)
>>> > elapsed time: 0.170916977 seconds (45785624 bytes allocated)
>>> > elapsed time: 0.171598156 seconds (45782760 bytes allocated)
>>> > elapsed time: 0.173866309 seconds (45779896 bytes allocated)
>>> > elapsed time: 0.170267172 seconds (45777032 bytes allocated)
>>> > elapsed time: 0.171754713 seconds (45774168 bytes allocated)
>>> > elapsed time: 0.170110142 seconds (45771304 bytes allocated)
>>> > elapsed time: 0.175199053 seconds (45768440 bytes allocated)
>>> > elapsed time: 0.179893161 seconds (45765576 bytes allocated)
>>> > elapsed time: 0.212172824 seconds (45762712 bytes allocated)
>>> > elapsed time: 0.252750549 seconds (45759848 bytes allocated)
>>> > elapsed time: 0.254874855 seconds (45756984 bytes allocated)
>>> > elapsed time: 0.231003319 seconds (45754120 bytes allocated)
>>> > elapsed time: 0.235060195 seconds (45751256 bytes allocated)
>>> > elapsed time: 0.235379355 seconds (45748392 bytes allocated)
>>> > elapsed time: 0.927622743 seconds (45746168 bytes allocated, 77.65% gc
>>> time)
>>> > elapsed time: 0.9132931 seconds (45742664 bytes allocated, 78.35% gc
>>> time)
>>> >
>>> > But as soon as it starts doing gc the % time spent in increases almost
>>> > indefinitely, output from time much later:
>>> >
>>> > elapsed time: 0.174122929 seconds (36239160 bytes allocated)
>>> > elapsed time: 18.535572658 seconds (36236168 bytes allocated, 99.22%
>>> gc
>>> > time)
>>> > elapsed time: 19.189478819 seconds (36233176 bytes allocated, 99.26%
>>> gc
>>> > time)
>>> > elapsed time: 21.812889439 seconds (36230184 bytes allocated, 99.35%
>>> gc
>>> > time)
>>> > elapsed time: 22.182467723 seconds (36227192 bytes allocated, 99.30%
>>> gc
>>> > time)
>>> > elapsed time: 0.169849999 seconds (36224200 bytes allocated)
>>> >
>>> > The inner loop, despite iterating over fewer and fewer indices has
>>> > massively increased the gc, and therefore overall, execution time. I
>>> have
>>> > tried many things, including creating the compute function,
>>> devectorizing
>>> > the ratios calculation (which really slowed things down), using view
>>> and
>>> > sub in various places, profiling with --trace-allocation=all but I
>>> can't
>>> > figure out why this happens or how to fix it. Doing gc for 22 seconds
>>> > obviously kills the performance, and since there are about 22M
>>> iterations
>>> > this is prohibitive. Can anyone suggest something I can try to improve
>>> the
>>> > performance here?
>>> >
>>> > Thanks,
>>> > Adam
>>>
>>>
