[Met_help] [rt.rap.ucar.edu #56519] History for Question about pb2nc
Paul Oldenburg via RT
met_help at ucar.edu
Mon Jun 11 09:05:41 MDT 2012
----------------------------------------------------------------
Initial Request
----------------------------------------------------------------
Ever since I updated my MET software to v3.1, I have noticed long wait times for pb2nc to return control to the shell after processing a PREPBUFR file. In general, it will only take 1-2 minutes for pb2nc to convert a PREPBUFR data file to netCDF, but I then need to wait approximately 45 minutes for pb2nc to end its process and return control to the shell. I have tested this on the sample PREPBUFR data file and configuration that come with the MET distribution, and have no problem with wait times there. Rather, this occurs when I'm processing the PREPBUFR files provided by NCEP. An example file for reference is located on the /glade filesystem at /glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le. Note that this is a PREPBUFR file I've converted to little endian for processing in a linux environment.
Have you noticed this same issue, or have any other users reported the same problem?
Thanks for any help with this,
- Tom
Thomas Cram
NCAR / CISL / Data Support Section
303-497-1217
tcram at ucar.edu
dss.ucar.edu
----------------------------------------------------------------
Complete Ticket History
----------------------------------------------------------------
Subject: Re: [rt.rap.ucar.edu #56519] Question about pb2nc
From: Paul Oldenburg
Time: Fri May 18 14:44:51 2012
Thomas,
I'm not sure if I'm reproducing your problem or not. When I ran the
test below, which did take 27 minutes, most of the
time was spent in the "Processing 405646 PrepBufr messages..." phase.
The exact same command ran in 5 minutes on my
development host. Is the behavoir you are seeing that most of the
delay occurs after the final status message is
printed? Are you observing the problematic pb2nc behavior on a
bluefire login host or when it runs as a queued job?
Paul
[pgoldenb at be1005en met_help.cram]$ time
/glade/home/johnhg/MET/MET_releases/METv3.1/bin/pb2nc \
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
\
pb_test.nc PB2NCConfig
DEBUG 1: Reading Default Config File:
/glade/home/johnhg/MET/MET_releases/METv3.1/data/config/PB2NCConfig_default
DEBUG 1: Reading User Config File: PB2NCConfig
DEBUG 1: Creating NetCDF File: pb_test.nc
DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
DEBUG 1: Blocking PrepBufr file to: /tmp/tmp_pb2nc_blk_373696_0
"/glade/home/johnhg/MET/MET_releases/METv3.1/src/tools/other/pb2nc/openpb.f",
line 20: 1525-126 The file name provided
in the OPEN statement for unit 11 contains a null character. The
program will recover by using the file name
/tmp/tmp_pb2nc_blk_373696_0.
DEBUG 2: PrepBufr Time Center: 20120517_000000
DEBUG 2: Searching Time Window: 20120516_233000 to
20120517_003000
DEBUG 2: Processing 405646 PrepBufr messages...
5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85% 90%
95% 100%
DEBUG 2: Total PrepBufr Messages processed = 405646
DEBUG 2: Rejected based on message type = 0
DEBUG 2: Rejected based on station id = 0
DEBUG 2: Rejected based on valid time = 283682
DEBUG 2: Rejected based on masking grid = 0
DEBUG 2: Rejected based on masking polygon = 0
DEBUG 2: Rejected based on elevation = 0
DEBUG 2: Rejected based on pb report type = 0
DEBUG 2: Rejected based on input report type = 0
DEBUG 2: Rejected based on instrument type = 0
DEBUG 2: Rejected based on zero observations = 18117
DEBUG 2: Total PrepBufr Messages retained = 103847
DEBUG 2: Total observations retained or derived = 402984
real 27m1.377s
user 25m41.858s
sys 0m45.053s
On 05/18/2012 01:00 PM, Thomas Cram via RT wrote:
>
> Fri May 18 13:00:07 2012: Request 56519 was acted upon.
> Transaction: Ticket created by tcram at ucar.edu
> Queue: met_help
> Subject: Question about pb2nc
> Owner: Nobody
> Requestors: tcram at ucar.edu
> Status: new
> Ticket<URL:
https://rt.rap.ucar.edu/rt/Ticket/Display.html?id=56519>
>
>
> Ever since I updated my MET software to v3.1, I have noticed long
wait times for pb2nc to return control to the shell after processing a
PREPBUFR file. In general, it will only take 1-2 minutes for pb2nc to
convert a PREPBUFR data file to netCDF, but I then need to wait
approximately 45 minutes for pb2nc to end its process and return
control to the shell. I have tested this on the sample PREPBUFR data
file and configuration that come with the MET distribution, and have
no problem with wait times there. Rather, this occurs when I'm
processing the PREPBUFR files provided by NCEP. An example file for
reference is located on the /glade filesystem at
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le.
Note that this is a PREPBUFR file I've converted to little endian for
processing in a linux environment.
>
> Have you noticed this same issue, or have any other users reported
the same problem?
>
> Thanks for any help with this,
> - Tom
>
>
> Thomas Cram
> NCAR / CISL / Data Support Section
> 303-497-1217
> tcram at ucar.edu
> dss.ucar.edu
>
>
>
>
------------------------------------------------
Subject: Question about pb2nc
From: Thomas Cram
Time: Mon May 21 13:41:47 2012
Hi Paul,
I'm running pb2nc interactively on the mirage nodes and evans, which
is a linux machine we use within our group. Most of the delay I'm
observing occurs after the final status message, "Total observations
retained or derived". It generally only takes 2-3 minutes to get to
this final status message, then the long wait occurs before control is
returned to the shell.
I've done tests on three different machines -- mirage3, mirage5, and
evans -- see below for the results. Evans was the fastest at 20
minutes, followed by mirage3 (1 h 28 min) and mirage5 (2 h 22 min).
I'm guessing the mirage5 test took so long because that node was busy
running simultaneous processes for other users.
In my pb2nc configuration (see attached), I have it set up to retain
pretty much all the messages in the PREPBUFR data file. Basically, my
goal is to convert all the prepbufr messages into netCDF. I'm
wondering if this is a factor in the long wait times.
Thanks for looking into this!
- Tom
------------------------------------------------------------------------------------------------------------------------------------------
mirage3:
[tcram at mirage3 20120517.nr]$ time pb2nc
$DSSZONE/ds337.0/little_endian/prepbufr.gdas.2012051712.nr.le
prepbufr.gdas.2012051712.mirage3.nc ../config/PB2NCConfig_ds337.0
DEBUG 1: Reading Default Config File:
/glade/home/tcram/METv3.1/data/config/PB2NCConfig_default
DEBUG 1: Reading User Config File: ../config/PB2NCConfig_ds337.0
DEBUG 1: Creating NetCDF File: prepbufr.gdas.2012051712.mirage3.nc
DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051712.nr.le
DEBUG 1: Blocking PrepBufr file to:
/glade/data02/dsswork/ptmp/tmp_pb2nc_blk_2378_0
DEBUG 2: PrepBufr Time Center: 20120517_120000
DEBUG 2: Searching Time Window: 20120517_090000 to 20120517_150000
DEBUG 2: Processing 423931 PrepBufr messages...
5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85% 90%
95%
DEBUG 2: Total PrepBufr Messages processed = 423931
DEBUG 2: Rejected based on message type = 0
DEBUG 2: Rejected based on station id = 0
DEBUG 2: Rejected based on valid time = 0
DEBUG 2: Rejected based on masking grid = 0
DEBUG 2: Rejected based on masking polygon = 0
DEBUG 2: Rejected based on elevation = 0
DEBUG 2: Rejected based on pb report type = 0
DEBUG 2: Rejected based on input report type = 0
DEBUG 2: Rejected based on instrument type = 0
DEBUG 2: Rejected based on zero observations = 3043
DEBUG 2: Total PrepBufr Messages retained = 420888
DEBUG 2: Total observations retained or derived = 1962012
160.935u 5062.233s 1:28:27.73 98.4% 0+0k 0+0io 0pf+0w
------------------------------------------------------------------------------------------------------------------------------------------
mirage5:
108 mirage5:tcram% time pb2nc prepbufr.gdas.20120517.t12z.nr
prepbufr.gdas.2012051712.nc ../config/PB2NCConfig_ds337.0
DEBUG 1: Reading Default Config File:
/glade/home/tcram/METv3.1/data/config/PB2NCConfig_default
DEBUG 1: Reading User Config File: ../config/PB2NCConfig_ds337.0
DEBUG 1: Creating NetCDF File: prepbufr.gdas.2012051712.nc
DEBUG 1: Processing PrepBufr File: prepbufr.gdas.20120517.t12z.nr
DEBUG 1: Blocking PrepBufr file to:
/glade/data02/dsswork/ptmp/tmp_pb2nc_blk_21366_0
DEBUG 2: PrepBufr Time Center: 20120517_120000
DEBUG 2: Searching Time Window: 20120517_090000 to 20120517_150000
DEBUG 2: Processing 423931 PrepBufr messages...
5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85% 90%
95%
DEBUG 2: Total PrepBufr Messages processed = 423931
DEBUG 2: Rejected based on message type = 0
DEBUG 2: Rejected based on station id = 0
DEBUG 2: Rejected based on valid time = 0
DEBUG 2: Rejected based on masking grid = 0
DEBUG 2: Rejected based on masking polygon = 0
DEBUG 2: Rejected based on elevation = 0
DEBUG 2: Rejected based on pb report type = 0
DEBUG 2: Rejected based on input report type = 0
DEBUG 2: Rejected based on instrument type = 0
DEBUG 2: Rejected based on zero observations = 3043
DEBUG 2: Total PrepBufr Messages retained = 420888
DEBUG 2: Total observations retained or derived = 1962012
202.483u 7951.702s 2:22:04.87 95.6% 0+0k 0+0io 0pf+0w
------------------------------------------------------------------------------------------------------------------------------------------
evans:
113 evans.ucar.edu:tcram% time pb2nc
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
prepbufr.gdas.2012051700.evans.nc ../config/PB2NCConfig_ds337.0
DEBUG 1: Reading Default Config File:
/glade/home/tcram/METv3.1/data/config/PB2NCConfig_default
DEBUG 1: Reading User Config File: ../config/PB2NCConfig_ds337.0
DEBUG 1: Creating NetCDF File: prepbufr.gdas.2012051700.evans.nc
DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
DEBUG 1: Blocking PrepBufr file to:
/glade/data02/dsswork/ptmp/tmp_pb2nc_blk_14961_0
DEBUG 2: PrepBufr Time Center: 20120517_000000
DEBUG 2: Searching Time Window: 20120516_210000 to 20120517_030000
DEBUG 2: Processing 405646 PrepBufr messages...
5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85% 90%
95% 100%
DEBUG 2: Total PrepBufr Messages processed = 405646
DEBUG 2: Rejected based on message type = 0
DEBUG 2: Rejected based on station id = 0
DEBUG 2: Rejected based on valid time = 0
DEBUG 2: Rejected based on masking grid = 0
DEBUG 2: Rejected based on masking polygon = 0
DEBUG 2: Rejected based on elevation = 0
DEBUG 2: Rejected based on pb report type = 0
DEBUG 2: Rejected based on input report type = 0
DEBUG 2: Rejected based on instrument type = 0
DEBUG 2: Rejected based on zero observations = 3359
DEBUG 2: Total PrepBufr Messages retained = 402287
DEBUG 2: Total observations retained or derived = 1900607
78.612u 1114.657s 20:16.93 98.0% 0+0k 0+0io 0pf+0w
On May 18, 2012, at 2:44 PM, Paul Oldenburg via RT wrote:
> Thomas,
>
> I'm not sure if I'm reproducing your problem or not. When I ran the
test below, which did take 27 minutes, most of the
> time was spent in the "Processing 405646 PrepBufr messages..."
phase. The exact same command ran in 5 minutes on my
> development host. Is the behavoir you are seeing that most of the
delay occurs after the final status message is
> printed? Are you observing the problematic pb2nc behavior on a
bluefire login host or when it runs as a queued job?
>
> Paul
>
>
>
> [pgoldenb at be1005en met_help.cram]$ time
/glade/home/johnhg/MET/MET_releases/METv3.1/bin/pb2nc \
>
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
\
> pb_test.nc PB2NCConfig
> DEBUG 1: Reading Default Config File:
/glade/home/johnhg/MET/MET_releases/METv3.1/data/config/PB2NCConfig_default
> DEBUG 1: Reading User Config File: PB2NCConfig
> DEBUG 1: Creating NetCDF File: pb_test.nc
> DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
> DEBUG 1: Blocking PrepBufr file to: /tmp/tmp_pb2nc_blk_373696_0
>
"/glade/home/johnhg/MET/MET_releases/METv3.1/src/tools/other/pb2nc/openpb.f",
line 20: 1525-126 The file name provided
> in the OPEN statement for unit 11 contains a null character. The
program will recover by using the file name
> /tmp/tmp_pb2nc_blk_373696_0.
> DEBUG 2: PrepBufr Time Center: 20120517_000000
> DEBUG 2: Searching Time Window: 20120516_233000 to
20120517_003000
> DEBUG 2: Processing 405646 PrepBufr messages...
> 5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85%
90% 95% 100%
> DEBUG 2: Total PrepBufr Messages processed = 405646
> DEBUG 2: Rejected based on message type = 0
> DEBUG 2: Rejected based on station id = 0
> DEBUG 2: Rejected based on valid time = 283682
> DEBUG 2: Rejected based on masking grid = 0
> DEBUG 2: Rejected based on masking polygon = 0
> DEBUG 2: Rejected based on elevation = 0
> DEBUG 2: Rejected based on pb report type = 0
> DEBUG 2: Rejected based on input report type = 0
> DEBUG 2: Rejected based on instrument type = 0
> DEBUG 2: Rejected based on zero observations = 18117
> DEBUG 2: Total PrepBufr Messages retained = 103847
> DEBUG 2: Total observations retained or derived = 402984
>
> real 27m1.377s
> user 25m41.858s
> sys 0m45.053s
>
>
> On 05/18/2012 01:00 PM, Thomas Cram via RT wrote:
>>
>> Fri May 18 13:00:07 2012: Request 56519 was acted upon.
>> Transaction: Ticket created by tcram at ucar.edu
>> Queue: met_help
>> Subject: Question about pb2nc
>> Owner: Nobody
>> Requestors: tcram at ucar.edu
>> Status: new
>> Ticket<URL:
https://rt.rap.ucar.edu/rt/Ticket/Display.html?id=56519>
>>
>>
>> Ever since I updated my MET software to v3.1, I have noticed long
wait times for pb2nc to return control to the shell after processing a
PREPBUFR file. In general, it will only take 1-2 minutes for pb2nc to
convert a PREPBUFR data file to netCDF, but I then need to wait
approximately 45 minutes for pb2nc to end its process and return
control to the shell. I have tested this on the sample PREPBUFR data
file and configuration that come with the MET distribution, and have
no problem with wait times there. Rather, this occurs when I'm
processing the PREPBUFR files provided by NCEP. An example file for
reference is located on the /glade filesystem at
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le.
Note that this is a PREPBUFR file I've converted to little endian for
processing in a linux environment.
>>
>> Have you noticed this same issue, or have any other users reported
the same problem?
>>
>> Thanks for any help with this,
>> - Tom
>>
>>
>> Thomas Cram
>> NCAR / CISL / Data Support Section
>> 303-497-1217
>> tcram at ucar.edu
>> dss.ucar.edu
>>
>>
>>
>>
>
>
Thomas Cram
NCAR / CISL / Data Support Section
303-497-1217
tcram at ucar.edu
dss.ucar.edu
------------------------------------------------
Subject: Re: [rt.rap.ucar.edu #56519] Question about pb2nc
From: Paul Oldenburg
Time: Mon May 21 14:28:22 2012
Tom,
The main task that pb2nc does after printing the "observations
retained or derived" message is to write the observations
to a NetCDF file. I suspect that this step is where the delay you
observe is occurring. Would it be possible to try
running pb2nc and then monitoring the disk I/O using the iostat
command? Also, is it possible to write the pb2nc output
files on a different physical disk to see if performance improves in
that case?
Thanks,
Paul
On 05/21/2012 01:41 PM, Thomas Cram via RT wrote:
>
> <URL: https://rt.rap.ucar.edu/rt/Ticket/Display.html?id=56519>
>
> Hi Paul,
>
> I'm running pb2nc interactively on the mirage nodes and evans, which
is a linux machine we use within our group. Most of the delay I'm
observing occurs after the final status message, "Total observations
retained or derived". It generally only takes 2-3 minutes to get to
this final status message, then the long wait occurs before control is
returned to the shell.
>
> I've done tests on three different machines -- mirage3, mirage5, and
evans -- see below for the results. Evans was the fastest at 20
minutes, followed by mirage3 (1 h 28 min) and mirage5 (2 h 22 min).
I'm guessing the mirage5 test took so long because that node was busy
running simultaneous processes for other users.
>
> In my pb2nc configuration (see attached), I have it set up to retain
pretty much all the messages in the PREPBUFR data file. Basically, my
goal is to convert all the prepbufr messages into netCDF. I'm
wondering if this is a factor in the long wait times.
>
> Thanks for looking into this!
> - Tom
>
>
------------------------------------------------------------------------------------------------------------------------------------------
>
> mirage3:
> [tcram at mirage3 20120517.nr]$ time pb2nc
$DSSZONE/ds337.0/little_endian/prepbufr.gdas.2012051712.nr.le
prepbufr.gdas.2012051712.mirage3.nc ../config/PB2NCConfig_ds337.0
> DEBUG 1: Reading Default Config File:
/glade/home/tcram/METv3.1/data/config/PB2NCConfig_default
> DEBUG 1: Reading User Config File: ../config/PB2NCConfig_ds337.0
> DEBUG 1: Creating NetCDF File: prepbufr.gdas.2012051712.mirage3.nc
> DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051712.nr.le
> DEBUG 1: Blocking PrepBufr file to:
/glade/data02/dsswork/ptmp/tmp_pb2nc_blk_2378_0
> DEBUG 2: PrepBufr Time Center: 20120517_120000
> DEBUG 2: Searching Time Window: 20120517_090000 to 20120517_150000
> DEBUG 2: Processing 423931 PrepBufr messages...
> 5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85%
90% 95%
> DEBUG 2: Total PrepBufr Messages processed = 423931
> DEBUG 2: Rejected based on message type = 0
> DEBUG 2: Rejected based on station id = 0
> DEBUG 2: Rejected based on valid time = 0
> DEBUG 2: Rejected based on masking grid = 0
> DEBUG 2: Rejected based on masking polygon = 0
> DEBUG 2: Rejected based on elevation = 0
> DEBUG 2: Rejected based on pb report type = 0
> DEBUG 2: Rejected based on input report type = 0
> DEBUG 2: Rejected based on instrument type = 0
> DEBUG 2: Rejected based on zero observations = 3043
> DEBUG 2: Total PrepBufr Messages retained = 420888
> DEBUG 2: Total observations retained or derived = 1962012
>
> 160.935u 5062.233s 1:28:27.73 98.4% 0+0k 0+0io 0pf+0w
>
>
------------------------------------------------------------------------------------------------------------------------------------------
>
> mirage5:
> 108 mirage5:tcram% time pb2nc prepbufr.gdas.20120517.t12z.nr
prepbufr.gdas.2012051712.nc ../config/PB2NCConfig_ds337.0
> DEBUG 1: Reading Default Config File:
/glade/home/tcram/METv3.1/data/config/PB2NCConfig_default
> DEBUG 1: Reading User Config File: ../config/PB2NCConfig_ds337.0
> DEBUG 1: Creating NetCDF File: prepbufr.gdas.2012051712.nc
> DEBUG 1: Processing PrepBufr File: prepbufr.gdas.20120517.t12z.nr
> DEBUG 1: Blocking PrepBufr file to:
/glade/data02/dsswork/ptmp/tmp_pb2nc_blk_21366_0
> DEBUG 2: PrepBufr Time Center: 20120517_120000
> DEBUG 2: Searching Time Window: 20120517_090000 to 20120517_150000
> DEBUG 2: Processing 423931 PrepBufr messages...
> 5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85%
90% 95%
> DEBUG 2: Total PrepBufr Messages processed = 423931
> DEBUG 2: Rejected based on message type = 0
> DEBUG 2: Rejected based on station id = 0
> DEBUG 2: Rejected based on valid time = 0
> DEBUG 2: Rejected based on masking grid = 0
> DEBUG 2: Rejected based on masking polygon = 0
> DEBUG 2: Rejected based on elevation = 0
> DEBUG 2: Rejected based on pb report type = 0
> DEBUG 2: Rejected based on input report type = 0
> DEBUG 2: Rejected based on instrument type = 0
> DEBUG 2: Rejected based on zero observations = 3043
> DEBUG 2: Total PrepBufr Messages retained = 420888
> DEBUG 2: Total observations retained or derived = 1962012
>
> 202.483u 7951.702s 2:22:04.87 95.6% 0+0k 0+0io 0pf+0w
>
>
------------------------------------------------------------------------------------------------------------------------------------------
> evans:
> 113 evans.ucar.edu:tcram% time pb2nc
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
prepbufr.gdas.2012051700.evans.nc ../config/PB2NCConfig_ds337.0
> DEBUG 1: Reading Default Config File:
/glade/home/tcram/METv3.1/data/config/PB2NCConfig_default
> DEBUG 1: Reading User Config File: ../config/PB2NCConfig_ds337.0
> DEBUG 1: Creating NetCDF File: prepbufr.gdas.2012051700.evans.nc
> DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
> DEBUG 1: Blocking PrepBufr file to:
/glade/data02/dsswork/ptmp/tmp_pb2nc_blk_14961_0
> DEBUG 2: PrepBufr Time Center: 20120517_000000
> DEBUG 2: Searching Time Window: 20120516_210000 to 20120517_030000
> DEBUG 2: Processing 405646 PrepBufr messages...
> 5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85%
90% 95% 100%
> DEBUG 2: Total PrepBufr Messages processed = 405646
> DEBUG 2: Rejected based on message type = 0
> DEBUG 2: Rejected based on station id = 0
> DEBUG 2: Rejected based on valid time = 0
> DEBUG 2: Rejected based on masking grid = 0
> DEBUG 2: Rejected based on masking polygon = 0
> DEBUG 2: Rejected based on elevation = 0
> DEBUG 2: Rejected based on pb report type = 0
> DEBUG 2: Rejected based on input report type = 0
> DEBUG 2: Rejected based on instrument type = 0
> DEBUG 2: Rejected based on zero observations = 3359
> DEBUG 2: Total PrepBufr Messages retained = 402287
> DEBUG 2: Total observations retained or derived = 1900607
>
> 78.612u 1114.657s 20:16.93 98.0% 0+0k 0+0io 0pf+0w
>
>
> On May 18, 2012, at 2:44 PM, Paul Oldenburg via RT wrote:
>
>> Thomas,
>>
>> I'm not sure if I'm reproducing your problem or not. When I ran
the test below, which did take 27 minutes, most of the
>> time was spent in the "Processing 405646 PrepBufr messages..."
phase. The exact same command ran in 5 minutes on my
>> development host. Is the behavoir you are seeing that most of the
delay occurs after the final status message is
>> printed? Are you observing the problematic pb2nc behavior on a
bluefire login host or when it runs as a queued job?
>>
>> Paul
>>
>>
>>
>> [pgoldenb at be1005en met_help.cram]$ time
/glade/home/johnhg/MET/MET_releases/METv3.1/bin/pb2nc \
>>
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
\
>> pb_test.nc PB2NCConfig
>> DEBUG 1: Reading Default Config File:
/glade/home/johnhg/MET/MET_releases/METv3.1/data/config/PB2NCConfig_default
>> DEBUG 1: Reading User Config File: PB2NCConfig
>> DEBUG 1: Creating NetCDF File: pb_test.nc
>> DEBUG 1: Processing PrepBufr File:
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le
>> DEBUG 1: Blocking PrepBufr file to: /tmp/tmp_pb2nc_blk_373696_0
>>
"/glade/home/johnhg/MET/MET_releases/METv3.1/src/tools/other/pb2nc/openpb.f",
line 20: 1525-126 The file name provided
>> in the OPEN statement for unit 11 contains a null character. The
program will recover by using the file name
>> /tmp/tmp_pb2nc_blk_373696_0.
>> DEBUG 2: PrepBufr Time Center: 20120517_000000
>> DEBUG 2: Searching Time Window: 20120516_233000 to
20120517_003000
>> DEBUG 2: Processing 405646 PrepBufr messages...
>> 5% 10% 15% 20% 25% 30% 35% 40% 45% 50% 55% 60% 65% 70% 75% 80% 85%
90% 95% 100%
>> DEBUG 2: Total PrepBufr Messages processed = 405646
>> DEBUG 2: Rejected based on message type = 0
>> DEBUG 2: Rejected based on station id = 0
>> DEBUG 2: Rejected based on valid time = 283682
>> DEBUG 2: Rejected based on masking grid = 0
>> DEBUG 2: Rejected based on masking polygon = 0
>> DEBUG 2: Rejected based on elevation = 0
>> DEBUG 2: Rejected based on pb report type = 0
>> DEBUG 2: Rejected based on input report type = 0
>> DEBUG 2: Rejected based on instrument type = 0
>> DEBUG 2: Rejected based on zero observations = 18117
>> DEBUG 2: Total PrepBufr Messages retained = 103847
>> DEBUG 2: Total observations retained or derived = 402984
>>
>> real 27m1.377s
>> user 25m41.858s
>> sys 0m45.053s
>>
>>
>> On 05/18/2012 01:00 PM, Thomas Cram via RT wrote:
>>>
>>> Fri May 18 13:00:07 2012: Request 56519 was acted upon.
>>> Transaction: Ticket created by tcram at ucar.edu
>>> Queue: met_help
>>> Subject: Question about pb2nc
>>> Owner: Nobody
>>> Requestors: tcram at ucar.edu
>>> Status: new
>>> Ticket<URL:
https://rt.rap.ucar.edu/rt/Ticket/Display.html?id=56519>
>>>
>>>
>>> Ever since I updated my MET software to v3.1, I have noticed long
wait times for pb2nc to return control to the shell after processing a
PREPBUFR file. In general, it will only take 1-2 minutes for pb2nc to
convert a PREPBUFR data file to netCDF, but I then need to wait
approximately 45 minutes for pb2nc to end its process and return
control to the shell. I have tested this on the sample PREPBUFR data
file and configuration that come with the MET distribution, and have
no problem with wait times there. Rather, this occurs when I'm
processing the PREPBUFR files provided by NCEP. An example file for
reference is located on the /glade filesystem at
/glade/data02/dsszone/ds337.0/little_endian/prepbufr.gdas.2012051700.nr.le.
Note that this is a PREPBUFR file I've converted to little endian for
processing in a linux environment.
>>>
>>> Have you noticed this same issue, or have any other users reported
the same problem?
>>>
>>> Thanks for any help with this,
>>> - Tom
>>>
>>>
>>> Thomas Cram
>>> NCAR / CISL / Data Support Section
>>> 303-497-1217
>>> tcram at ucar.edu
>>> dss.ucar.edu
>>>
>>>
>>>
>>>
>>
>>
>
> Thomas Cram
> NCAR / CISL / Data Support Section
> 303-497-1217
> tcram at ucar.edu
> dss.ucar.edu
>
>
>
------------------------------------------------
More information about the Met_help
mailing list