processing aren't working right. I think this is due to EBP_processing:L80

[burningsage]

https://github.com/emerald-geomodelling/emerald-beryl-pipeline/blob/master/beryl_pipeline/processing.py#L80

Task:
  - msg: Read config
    time: 2024-09-09 09:55:43,998
  - msg: Download files
    time: 2024-09-09 09:55:44,024
  - msg: Read data
    time: 2024-09-09 09:55:44,762
  - msg: Processing
    time: 2024-09-09 09:55:46,497
  - msg: Write data
    time: 2024-09-09 09:56:11,735
  - msg: Runtime error
    time: 2024-09-09 09:56:13,473
RunTask:
  - '2024-09-09 09:55:40,489: RunTask start'
  - '2024-09-09 09:55:40,717: RunTask config loaded'
  - '2024-09-09 09:55:40,980: RunTask environment made'
  - '2024-09-09 09:55:41,008: RunTask loaded environment'
  - >-
    2024-09-09 09:55:41,013: RunTask starting actual task2024-09-09
    09-55-41.013517
  - >-
    2024-09-09 09:56:07,063: =============== Reading SkyTEM xyz data
    ===============
  - '2024-09-09 09:56:07,068:   - Reading gex file.'
  - '2024-09-09 09:56:07,072: header [General] parsed'
  - '2024-09-09 09:56:07,076: header [Channel1] parsed'
  - '2024-09-09 09:56:07,079: header [Channel2] parsed'
  - '2024-09-09 09:56:07,083:   - Reading xyz file.'
  - '2024-09-09 09:56:07,086:   - building xyz dictionary'
  - '2024-09-09 09:56:07,090:   - Done reading the data package!'
  - >-
    2024-09-09 09:56:07,093:   - Time used to read and import the data package:
    0.7534830570220947 sec.
  - '2024-09-09 09:56:07,097: '
  - '2024-09-09 09:56:07,100: '
  - '2024-09-09 09:56:07,104: =============== Processing step 1 ==============='
  - '2024-09-09 09:56:07,107:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,111: '
  - '2024-09-09 09:56:07,115: =============== Processing step 2 ==============='
  - '2024-09-09 09:56:07,118:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,122: '
  - '2024-09-09 09:56:07,125: =============== Processing step 3 ==============='
  - '2024-09-09 09:56:07,129:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,132: '
  - '2024-09-09 09:56:07,136: =============== Processing step 4 ==============='
  - '2024-09-09 09:56:07,139:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,143: '
  - '2024-09-09 09:56:07,147: =============== Processing step 5 ==============='
  - '2024-09-09 09:56:07,150:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,154: '
  - '2024-09-09 09:56:07,158: =============== Processing step 6 ==============='
  - '2024-09-09 09:56:07,161:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,165: '
  - '2024-09-09 09:56:07,169: =============== Processing step 7 ==============='
  - '2024-09-09 09:56:07,172:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,176: '
  - '2024-09-09 09:56:07,180: =============== Processing step 8 ==============='
  - '2024-09-09 09:56:07,184:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,188: '
  - '2024-09-09 09:56:07,191: =============== Processing step 9 ==============='
  - '2024-09-09 09:56:07,195:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,199: '
  - '2024-09-09 09:56:07,203: =============== Processing step 10 ==============='
  - '2024-09-09 09:56:07,206:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,210: '
  - '2024-09-09 09:56:07,214: =============== Processing step 11 ==============='
  - '2024-09-09 09:56:07,218:   - Step name: ''Use manual edits'''
  - '2024-09-09 09:56:07,224: '
  - '2024-09-09 09:56:07,228: =============== Processing step 12 ==============='
  - >-
    2024-09-09 09:56:07,232:   - Step name: 'Disable soundings by tilt and
    altitude'
  - >-
    2024-09-09 09:56:07,236:   - Disabling based on roll (±10°), pitch(±10°),
    and altitude (110 m) limits
  - '2024-09-09 09:56:07,240:   - Pre-disable statistics:'
  - '2024-09-09 09:56:07,244:     - TxRoll:     3.57 ± 1.67 °'
  - '2024-09-09 09:56:07,247:     - TxPitch:    -3.71 ± 4.12 °'
  - '2024-09-09 09:56:07,251:     - TxAltitude: 39.59 ± 10.54 m'
  - '2024-09-09 09:56:07,255:   - Post-disable statistics:'
  - '2024-09-09 09:56:07,259:     - TxRoll:     3.52 ± 1.55 °'
  - '2024-09-09 09:56:07,263:     - TxPitch:    -3.71 ± 4.04 °'
  - '2024-09-09 09:56:07,267:     - TxAltitude: 39.45 ± 10.43 m'
  - >-
    2024-09-09 09:56:07,271:   - 1.97 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:07,275:   - Time used to disable data based on tilt and
    altitude: 0.020017623901367188 sec.
  - '2024-09-09 09:56:07,279: '
  - '2024-09-09 09:56:07,283: '
  - '2024-09-09 09:56:07,287: =============== Processing step 13 ==============='
  - '2024-09-09 09:56:07,291:   - Step name: ''Correct data and tilt for 1D'''
  - '2024-09-09 09:56:07,294:   - 1D Data and Tilt correction of the data'
  - '2024-09-09 09:56:07,298: '
  - '2024-09-09 09:56:07,302: Pre-Correction       TxRoll      TxPitch'
  - '2024-09-09 09:56:07,306: count           5634.000000  5634.000000'
  - '2024-09-09 09:56:07,310: mean               3.569290    -3.710861'
  - '2024-09-09 09:56:07,314: std                1.673224     4.119802'
  - '2024-09-09 09:56:07,318: min               -6.381000   -10.635000'
  - '2024-09-09 09:56:07,322: 25%                2.888000    -6.455750'
  - '2024-09-09 09:56:07,326: 50%                3.493000    -4.816500'
  - '2024-09-09 09:56:07,330: 75%                4.146750    -2.598500'
  - '2024-09-09 09:56:07,334: max               10.874000    10.390000'
  - '2024-09-09 09:56:07,337: '
  - '2024-09-09 09:56:07,342: Post-Correction  TxRoll  TxPitch'
  - '2024-09-09 09:56:07,345: count            5634.0   5634.0'
  - '2024-09-09 09:56:07,349: mean                0.0      0.0'
  - '2024-09-09 09:56:07,354: std                 0.0      0.0'
  - '2024-09-09 09:56:07,357: min                 0.0      0.0'
  - '2024-09-09 09:56:07,361: 25%                 0.0      0.0'
  - '2024-09-09 09:56:07,365: 50%                 0.0      0.0'
  - '2024-09-09 09:56:07,369: 75%                 0.0      0.0'
  - '2024-09-09 09:56:07,373: max                 0.0      0.0'
  - '2024-09-09 09:56:07,377: '
  - >-
    2024-09-09 09:56:07,381:   - Time used for 1D correction of the data:
    0.03927326202392578 sec.
  - '2024-09-09 09:56:07,385: '
  - '2024-09-09 09:56:07,389: '
  - '2024-09-09 09:56:07,393: =============== Processing step 14 ==============='
  - '2024-09-09 09:56:07,397:   - Step name: ''STD error: Replace from GEX'''
  - '2024-09-09 09:56:07,401:   - Adding gex-based STD error to data'
  - >-
    2024-09-09 09:56:07,405:   - Time used to add gex-based STD errors to data:
    0.00054168701171875 sec.
  - '2024-09-09 09:56:07,409: '
  - '2024-09-09 09:56:07,413: '
  - '2024-09-09 09:56:07,417: =============== Processing step 15 ==============='
  - '2024-09-09 09:56:07,421:   - Step name: ''STD error: Replace from GEX'''
  - '2024-09-09 09:56:07,425:   - Adding gex-based STD error to data'
  - >-
    2024-09-09 09:56:07,430:   - Time used to add gex-based STD errors to data:
    0.0006587505340576172 sec.
  - '2024-09-09 09:56:07,434: '
  - '2024-09-09 09:56:07,438: '
  - '2024-09-09 09:56:07,442: =============== Processing step 16 ==============='
  - '2024-09-09 09:56:07,446:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,450:   - Adding STD error to data'
  - '2024-09-09 09:56:07,454: STD_Ch01'
  - >-
    2024-09-09 09:56:07,458:   - Time used to add STD errors to data:
    0.0019235610961914062 sec.
  - '2024-09-09 09:56:07,462: '
  - '2024-09-09 09:56:07,466: '
  - '2024-09-09 09:56:07,471: =============== Processing step 17 ==============='
  - '2024-09-09 09:56:07,475:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,479:   - Adding STD error to data'
  - '2024-09-09 09:56:07,483: STD_Ch01'
  - >-
    2024-09-09 09:56:07,488:   - Time used to add STD errors to data:
    0.0016045570373535156 sec.
  - '2024-09-09 09:56:07,492: '
  - '2024-09-09 09:56:07,496: '
  - '2024-09-09 09:56:07,501: =============== Processing step 18 ==============='
  - '2024-09-09 09:56:07,505:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,509:   - Adding STD error to data'
  - '2024-09-09 09:56:07,513: STD_Ch01'
  - >-
    2024-09-09 09:56:07,517:   - Time used to add STD errors to data:
    0.0015788078308105469 sec.
  - '2024-09-09 09:56:07,522: '
  - '2024-09-09 09:56:07,526: '
  - '2024-09-09 09:56:07,530: =============== Processing step 19 ==============='
  - '2024-09-09 09:56:07,534:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,539:   - Adding STD error to data'
  - '2024-09-09 09:56:07,543: STD_Ch01'
  - >-
    2024-09-09 09:56:07,547:   - Time used to add STD errors to data:
    0.0013706684112548828 sec.
  - '2024-09-09 09:56:07,552: '
  - '2024-09-09 09:56:07,556: '
  - '2024-09-09 09:56:07,560: =============== Processing step 20 ==============='
  - '2024-09-09 09:56:07,565:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,570:   - Adding STD error to data'
  - '2024-09-09 09:56:07,574: STD_Ch01'
  - >-
    2024-09-09 09:56:07,578:   - Time used to add STD errors to data:
    0.0013413429260253906 sec.
  - '2024-09-09 09:56:07,582: '
  - '2024-09-09 09:56:07,587: '
  - '2024-09-09 09:56:07,591: =============== Processing step 21 ==============='
  - '2024-09-09 09:56:07,596:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,600:   - Adding STD error to data'
  - '2024-09-09 09:56:07,605: STD_Ch02'
  - >-
    2024-09-09 09:56:07,609:   - Time used to add STD errors to data:
    0.0021369457244873047 sec.
  - '2024-09-09 09:56:07,614: '
  - '2024-09-09 09:56:07,618: '
  - '2024-09-09 09:56:07,623: =============== Processing step 22 ==============='
  - '2024-09-09 09:56:07,628:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,632:   - Adding STD error to data'
  - '2024-09-09 09:56:07,637: STD_Ch02'
  - >-
    2024-09-09 09:56:07,641:   - Time used to add STD errors to data:
    0.0017309188842773438 sec.
  - '2024-09-09 09:56:07,646: '
  - '2024-09-09 09:56:07,650: '
  - '2024-09-09 09:56:07,655: =============== Processing step 23 ==============='
  - '2024-09-09 09:56:07,659:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,663:   - Adding STD error to data'
  - '2024-09-09 09:56:07,668: STD_Ch02'
  - >-
    2024-09-09 09:56:07,673:   - Time used to add STD errors to data:
    0.0016088485717773438 sec.
  - '2024-09-09 09:56:07,677: '
  - '2024-09-09 09:56:07,682: '
  - '2024-09-09 09:56:07,686: =============== Processing step 24 ==============='
  - '2024-09-09 09:56:07,691:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,696:   - Adding STD error to data'
  - '2024-09-09 09:56:07,700: STD_Ch02'
  - >-
    2024-09-09 09:56:07,705:   - Time used to add STD errors to data:
    0.0015001296997070312 sec.
  - '2024-09-09 09:56:07,709: '
  - '2024-09-09 09:56:07,714: '
  - '2024-09-09 09:56:07,718: =============== Processing step 25 ==============='
  - '2024-09-09 09:56:07,723:   - Step name: ''STD error: Add fractional error'''
  - '2024-09-09 09:56:07,727:   - Adding STD error to data'
  - '2024-09-09 09:56:07,732: STD_Ch02'
  - >-
    2024-09-09 09:56:07,736:   - Time used to add STD errors to data:
    0.0013544559478759766 sec.
  - '2024-09-09 09:56:07,741: '
  - '2024-09-09 09:56:07,746: '
  - '2024-09-09 09:56:07,750: =============== Processing step 26 ==============='
  - '2024-09-09 09:56:07,755:   - Step name: ''Disable gates by curvature max'''
  - >-
    2024-09-09 09:56:07,759:   - Disabling curvatures greater than 10 on
    channel-1 after gate-7
  - >-
    2024-09-09 09:56:07,764:   - Curvature statistics for all soundings after
    gate-7:
  - '2024-09-09 09:56:07,769:       pre_mean_curvature  = 0.012 ± 13.976'
  - '2024-09-09 09:56:07,773:       post_mean_curvature = -0.923 ± 4.497'
  - >-
    2024-09-09 09:56:07,778:   - 16.56 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:07,782:   - Time used for maximum curvature disabling:
    4.955035924911499 sec.
  - '2024-09-09 09:56:07,787: '
  - '2024-09-09 09:56:07,791: '
  - '2024-09-09 09:56:07,796: =============== Processing step 27 ==============='
  - '2024-09-09 09:56:07,800:   - Step name: ''Disable gates by curvature max'''
  - >-
    2024-09-09 09:56:07,805:   - Disabling curvatures greater than 10 on
    channel-2 after gate-13
  - >-
    2024-09-09 09:56:07,810:   - Curvature statistics for all soundings after
    gate-13:
  - '2024-09-09 09:56:07,814:       pre_mean_curvature  = 0.137 ± 29.107'
  - '2024-09-09 09:56:07,819:       post_mean_curvature = -2.502 ± 10.321'
  - >-
    2024-09-09 09:56:07,823:   - 32.86 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:07,828:   - Time used for maximum curvature disabling:
    4.918570518493652 sec.
  - '2024-09-09 09:56:07,833: '
  - '2024-09-09 09:56:07,837: '
  - '2024-09-09 09:56:07,842: =============== Processing step 28 ==============='
  - '2024-09-09 09:56:07,847:   - Step name: ''Disable gates by curvature min'''
  - >-
    2024-09-09 09:56:07,851:   - Disabling curvatures less than -10 on channel-1
    after gate-7
  - >-
    2024-09-09 09:56:07,856:   - Curvature statistics for all soundings after
    gate-7:
  - '2024-09-09 09:56:07,861:       pre_mean_curvature  = 0.012 ± 13.976'
  - '2024-09-09 09:56:07,866:       post_mean_curvature = 0.147 ± 3.988'
  - >-
    2024-09-09 09:56:07,870:   - 16.31 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:07,875:   - Time used for minimum curvature disabling:
    4.895517110824585 sec.
  - '2024-09-09 09:56:07,880: '
  - '2024-09-09 09:56:07,885: '
  - '2024-09-09 09:56:07,890: =============== Processing step 29 ==============='
  - '2024-09-09 09:56:07,895:   - Step name: ''Disable gates by curvature min'''
  - >-
    2024-09-09 09:56:07,900:   - Disabling curvatures less than -10 on channel-2
    after gate-13
  - >-
    2024-09-09 09:56:07,905:   - Curvature statistics for all soundings after
    gate-13:
  - '2024-09-09 09:56:07,910:       pre_mean_curvature  = 0.137 ± 29.107'
  - '2024-09-09 09:56:07,915:       post_mean_curvature = 1.158 ± 13.643'
  - >-
    2024-09-09 09:56:07,919:   - 32.9 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:07,924:   - Time used for minimum curvature disabling:
    5.045726776123047 sec.
  - '2024-09-09 09:56:07,929: '
  - '2024-09-09 09:56:07,934: '
  - '2024-09-09 09:56:07,939: =============== Processing step 30 ==============='
  - '2024-09-09 09:56:07,944:   - Step name: ''Disable gates by slope max'''
  - >-
    2024-09-09 09:56:07,949:   - Disabling slopes greater than 0 on channel-1
    after gate-7
  - >-
    2024-09-09 09:56:07,954:   - Slope statistics for all soundings after
    gate-7:
  - '2024-09-09 09:56:07,959:       pre_mean_slope  = -2.327 ± 3.356'
  - '2024-09-09 09:56:07,964:       post_mean_slope = -2.579 ± 1.83'
  - >-
    2024-09-09 09:56:07,969:   - 13.76 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:07,973:   - Time used for maximum slope disabling:
    0.020363807678222656 sec.
  - '2024-09-09 09:56:07,978: '
  - '2024-09-09 09:56:07,983: '
  - '2024-09-09 09:56:07,988: =============== Processing step 31 ==============='
  - '2024-09-09 09:56:07,993:   - Step name: ''Disable gates by slope max'''
  - >-
    2024-09-09 09:56:07,998:   - Disabling slopes greater than 0 on channel-2
    after gate-13
  - >-
    2024-09-09 09:56:08,003:   - Slope statistics for all soundings after
    gate-13:
  - '2024-09-09 09:56:08,008:       pre_mean_slope  = -2.222 ± 6.037'
  - '2024-09-09 09:56:08,013:       post_mean_slope = -3.341 ± 2.781'
  - >-
    2024-09-09 09:56:08,018:   - 29.26 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:08,023:   - Time used for maximum slope disabling:
    0.026198863983154297 sec.
  - '2024-09-09 09:56:08,028: '
  - '2024-09-09 09:56:08,032: '
  - '2024-09-09 09:56:08,037: =============== Processing step 32 ==============='
  - '2024-09-09 09:56:08,042:   - Step name: ''Disable gates by slope min'''
  - >-
    2024-09-09 09:56:08,047:   - Disabling slopes less than -5 on channel-1
    after gate-7
  - >-
    2024-09-09 09:56:08,052:   - Slope statistics for all soundings after
    gate-7:
  - '2024-09-09 09:56:08,057:       pre_mean_slope  = -2.327 ± 3.356'
  - '2024-09-09 09:56:08,062:       post_mean_slope = -2.208 ± 0.954'
  - >-
    2024-09-09 09:56:14,385:   - 16.32 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:14,392:   - Time used for minimum slope disabling:
    0.01946735382080078 sec.
  - '2024-09-09 09:56:14,397: '
  - '2024-09-09 09:56:14,402: '
  - '2024-09-09 09:56:14,407: =============== Processing step 33 ==============='
  - '2024-09-09 09:56:14,412:   - Step name: ''Disable gates by slope min'''
  - >-
    2024-09-09 09:56:14,418:   - Disabling slopes less than -5 on channel-2
    after gate-13
  - >-
    2024-09-09 09:56:14,423:   - Slope statistics for all soundings after
    gate-13:
  - '2024-09-09 09:56:14,428:       pre_mean_slope  = -2.222 ± 6.037'
  - '2024-09-09 09:56:14,433:       post_mean_slope = -2.44 ± 1.795'
  - >-
    2024-09-09 09:56:14,438:   - 32.33 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:14,443:   - Time used for minimum slope disabling:
    0.026695966720581055 sec.
  - '2024-09-09 09:56:14,449: '
  - '2024-09-09 09:56:14,454: '
  - '2024-09-09 09:56:14,459: =============== Processing step 34 ==============='
  - '2024-09-09 09:56:14,464:   - Step name: ''Save intermediate results'''
  - '2024-09-09 09:56:14,469: '
  - '2024-09-09 09:56:14,474: =============== Processing step 35 ==============='
  - '2024-09-09 09:56:14,480:   - Step name: ''Moving average filter'''
  - '2024-09-09 09:56:14,485:   - Running a moving average filter  (line by line)'
  - '2024-09-09 09:56:14,490: Filtering line: 500101'
  - '2024-09-09 09:56:14,495: filtering: Gate_Ch01 with filters [5, 9]'
  - '2024-09-09 09:56:14,501: filtering: Gate_Ch02 with filters [7, 13]'
  - '2024-09-09 09:56:14,506: filtering: STD_Ch01 with filters [5, 9]'
  - >-
    2024-09-09 09:56:14,511: calculating average - STD for STD_Ch01 using
    rolling lengths:[5, 9]
  - '2024-09-09 09:56:14,516: filtering: STD_Ch02 with filters [7, 13]'
  - >-
    2024-09-09 09:56:14,522: calculating average - STD for STD_Ch02 using
    rolling lengths:[7, 13]
  - '2024-09-09 09:56:14,527: Filtering line: 500201'
  - '2024-09-09 09:56:14,532: filtering: Gate_Ch01 with filters [5, 9]'
  - '2024-09-09 09:56:14,537: filtering: Gate_Ch02 with filters [7, 13]'
  - '2024-09-09 09:56:14,542: filtering: STD_Ch01 with filters [5, 9]'
  - >-
    2024-09-09 09:56:14,548: calculating average - STD for STD_Ch01 using
    rolling lengths:[5, 9]
  - '2024-09-09 09:56:14,553: filtering: STD_Ch02 with filters [7, 13]'
  - >-
    2024-09-09 09:56:14,559: calculating average - STD for STD_Ch02 using
    rolling lengths:[7, 13]
  - '2024-09-09 09:56:14,564: Filtering line: 500301'
  - '2024-09-09 09:56:14,569: filtering: Gate_Ch01 with filters [5, 9]'
  - '2024-09-09 09:56:14,575: filtering: Gate_Ch02 with filters [7, 13]'
  - '2024-09-09 09:56:14,580: filtering: STD_Ch01 with filters [5, 9]'
  - >-
    2024-09-09 09:56:14,586: calculating average - STD for STD_Ch01 using
    rolling lengths:[5, 9]
  - '2024-09-09 09:56:14,591: filtering: STD_Ch02 with filters [7, 13]'
  - >-
    2024-09-09 09:56:14,596: calculating average - STD for STD_Ch02 using
    rolling lengths:[7, 13]
  - '2024-09-09 09:56:14,602: Filtering line: 500102'
  - '2024-09-09 09:56:14,607: filtering: Gate_Ch01 with filters [5, 9]'
  - '2024-09-09 09:56:14,612: filtering: Gate_Ch02 with filters [7, 13]'
  - '2024-09-09 09:56:14,618: filtering: STD_Ch01 with filters [5, 9]'
  - >-
    2024-09-09 09:56:14,623: calculating average - STD for STD_Ch01 using
    rolling lengths:[5, 9]
  - '2024-09-09 09:56:14,629: filtering: STD_Ch02 with filters [7, 13]'
  - >-
    2024-09-09 09:56:14,634: calculating average - STD for STD_Ch02 using
    rolling lengths:[7, 13]
  - '2024-09-09 09:56:14,640: Filtering line: 500202'
  - '2024-09-09 09:56:14,645: filtering: Gate_Ch01 with filters [5, 9]'
  - '2024-09-09 09:56:14,651: filtering: Gate_Ch02 with filters [7, 13]'
  - '2024-09-09 09:56:14,656: filtering: STD_Ch01 with filters [5, 9]'
  - >-
    2024-09-09 09:56:14,661: calculating average - STD for STD_Ch01 using
    rolling lengths:[5, 9]
  - '2024-09-09 09:56:14,667: filtering: STD_Ch02 with filters [7, 13]'
  - >-
    2024-09-09 09:56:14,672: calculating average - STD for STD_Ch02 using
    rolling lengths:[7, 13]
  - >-
    2024-09-09 09:56:14,678:   - Time used for moving average filter:
    0.43157386779785156 sec.
  - '2024-09-09 09:56:14,683: '
  - '2024-09-09 09:56:14,689: =============== Processing step 36 ==============='
  - '2024-09-09 09:56:14,694:   - Step name: ''Disable gates by STD values'''
  - >-
    2024-09-09 09:56:14,700:   - Disabling channel-1 after gate-5 based on 0.09
    STD threshold
  - >-
    2024-09-09 09:56:14,705:   - 0.0 % of the data have been deactivated by this
    filter
  - >-
    2024-09-09 09:56:14,710:   - Time used for STD based disabling:
    0.006296634674072266 sec.
  - '2024-09-09 09:56:14,716: '
  - '2024-09-09 09:56:14,721: '
  - '2024-09-09 09:56:14,727: =============== Processing step 37 ==============='
  - '2024-09-09 09:56:14,732:   - Step name: ''Disable gates by STD values'''
  - >-
    2024-09-09 09:56:14,738:   - Disabling channel-2 after gate-13 based on 0.09
    STD threshold
  - >-
    2024-09-09 09:56:14,743:   - 0.0 % of the data have been deactivated by this
    filter
  - >-
    2024-09-09 09:56:14,749:   - Time used for STD based disabling:
    0.007216453552246094 sec.
  - '2024-09-09 09:56:14,754: '
  - '2024-09-09 09:56:14,760: '
  - '2024-09-09 09:56:14,765: =============== Processing step 38 ==============='
  - '2024-09-09 09:56:14,771:   - Step name: ''Disable gates by negative data'''
  - >-
    2024-09-09 09:56:14,776:   - Disabling negative data from channel-1 after
    gate-5
  - >-
    2024-09-09 09:56:14,782:   - 0.0 % of the data have been deactivated by this
    filter
  - >-
    2024-09-09 09:56:14,787:   - Time used to disable negative data:
    0.0058057308197021484 sec.
  - '2024-09-09 09:56:14,793: '
  - '2024-09-09 09:56:14,798: '
  - '2024-09-09 09:56:14,804: =============== Processing step 39 ==============='
  - '2024-09-09 09:56:14,810:   - Step name: ''Disable gates by negative data'''
  - >-
    2024-09-09 09:56:14,815:   - Disabling negative data from channel-2 after
    gate-13
  - >-
    2024-09-09 09:56:14,821:   - 0.0 % of the data have been deactivated by this
    filter
  - >-
    2024-09-09 09:56:14,826:   - Time used to disable negative data:
    0.006989717483520508 sec.
  - '2024-09-09 09:56:14,832: '
  - '2024-09-09 09:56:14,838: '
  - '2024-09-09 09:56:14,843: =============== Processing step 40 ==============='
  - >-
    2024-09-09 09:56:14,849:   - Step name: 'Disable soundings by number of
    active gates'
  - >-
    2024-09-09 09:56:14,854:   - Disabling soundings with too few timegates from
    channel-1
  - >-
    2024-09-09 09:56:14,860:   - 6.98 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:14,865:   - Time used for sounding disabling:
    0.00322723388671875 sec.
  - '2024-09-09 09:56:14,871: '
  - '2024-09-09 09:56:14,877: '
  - '2024-09-09 09:56:14,882: =============== Processing step 41 ==============='
  - >-
    2024-09-09 09:56:14,888:   - Step name: 'Disable soundings by number of
    active gates'
  - >-
    2024-09-09 09:56:14,894:   - Disabling soundings with too few timegates from
    channel-2
  - >-
    2024-09-09 09:56:14,899:   - 32.55 % of the data have been deactivated by
    this filter
  - >-
    2024-09-09 09:56:14,905:   - Time used for sounding disabling:
    0.0039386749267578125 sec.
  - '2024-09-09 09:56:14,911: '
  - >-
    2024-09-09 09:56:14,917: Pipeline failed:
    luigi.Processing('--module=beryl_pipeline.processing',
    '--processing-name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2',
    '--scheduler-url=http://scheduler:8082', '--retcode-already-running=10',
    '--retcode-missing-data=20', '--retcode-not-run=25',
    '--retcode-task-failed=30', '--retcode-scheduling-error=35',
    '--retcode-unhandled-exception=40') as 2054 (exit_code=30) in
    [134:/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml]:
  - ''
  - >-
    luigi.Processing('--module=beryl_pipeline.processing',
    '--processing-name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2',
    '--scheduler-url=http://scheduler:8082', '--retcode-already-running=10',
    '--retcode-missing-data=20', '--retcode-not-run=25',
    '--retcode-task-failed=30', '--retcode-scheduling-error=35',
    '--retcode-unhandled-exception=40') as 2054 (exit_code=30) in
    [134:/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml]
  - 'stderr content:'
  - >-
    Loading S3 module without the python package boto3. Will crash at runtime if
    S3 functionality is used.
  - >-
    DEBUG: Checking if
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
    is complete
  - >-
    DEBUG: Checking if
    Import(import_name=gs://experimental-pipeline-inversion-test/import/import-164-ringeriksbanen-5lines-nox)
    is complete
  - >-
    INFO: Informed scheduler that task  
    Processing_gs___experimenta_530bed4d8f   has status   PENDING
  - >-
    INFO: Informed scheduler that task   Import_gs___experimenta_0bc8fa99af  
    has status   DONE
  - 'INFO: Done scheduling tasks'
  - 'INFO: Running Worker with 1 processes'
  - 'DEBUG: Asking scheduler for work...'
  - 'DEBUG: Pending tasks: 1'
  - >-
    INFO: [pid 2054] Worker Worker(salt=1996346561, workers=1,
    host=7feb0e1c9131, username=root, pid=2054) running  
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
  - >-
    ERROR: [pid 2054] Worker Worker(salt=1996346561, workers=1,
    host=7feb0e1c9131, username=root, pid=2054) failed   
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
  - 'Traceback (most recent call last):'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/luigi/worker.py", line 210, in run'
  - '    new_deps = self._run_get_new_deps()'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/luigi/worker.py", line 138, in _run_get_new_deps'
  - '    task_gen = self.task.run()'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/beryl_pipeline/processing.py", line 80, in run'
  - '    fl_data.orig_xyz = data.orig_xyz_by_line[fline]'
  - 'KeyError: ''500101'''
  - 'DEBUG: 1 running tasks, waiting for next task to finish'
  - >-
    INFO: Informed scheduler that task  
    Processing_gs___experimenta_530bed4d8f   has status   FAILED
  - 'DEBUG: Asking scheduler for work...'
  - 'DEBUG: Done'
  - 'DEBUG: There are no more tasks to run at this time'
  - 'DEBUG: There are 1 pending tasks possibly being run by other workers'
  - 'DEBUG: There are 1 pending tasks unique to this worker'
  - 'DEBUG: There are 1 pending tasks last scheduled by this worker'
  - >-
    INFO: Worker Worker(salt=1996346561, workers=1, host=7feb0e1c9131,
    username=root, pid=2054) was stopped. Shutting down Keep-Alive thread
  - 'INFO: '
  - '===== Luigi Execution Summary ====='
  - ''
  - 'Scheduled 2 tasks of which:'
  - '* 1 complete ones were encountered:'
  - '    - 1 Import(import_name=gs://experimental-pipeline-inversion-test/import/import-164-ringeriksbanen-5lines-nox)'
  - '* 1 failed:'
  - '    - 1 Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)'
  - ''
  - This progress looks :( because there were failed tasks
  - ''
  - '===== Luigi Execution Summary ====='
  - ''
  - ''
  - ''
  - >-
    2024-09-09 09:56:14,923: Task failed: Pipeline failed:
    luigi.Processing('--module=beryl_pipeline.processing',
    '--processing-name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2',
    '--scheduler-url=http://scheduler:8082', '--retcode-already-running=10',
    '--retcode-missing-data=20', '--retcode-not-run=25',
    '--retcode-task-failed=30', '--retcode-scheduling-error=35',
    '--retcode-unhandled-exception=40') as 2054 (exit_code=30) in
    [134:/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml]:
  - ''
  - >-
    luigi.Processing('--module=beryl_pipeline.processing',
    '--processing-name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2',
    '--scheduler-url=http://scheduler:8082', '--retcode-already-running=10',
    '--retcode-missing-data=20', '--retcode-not-run=25',
    '--retcode-task-failed=30', '--retcode-scheduling-error=35',
    '--retcode-unhandled-exception=40') as 2054 (exit_code=30) in
    [134:/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml]
  - 'stderr content:'
  - >-
    Loading S3 module without the python package boto3. Will crash at runtime if
    S3 functionality is used.
  - >-
    DEBUG: Checking if
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
    is complete
  - >-
    DEBUG: Checking if
    Import(import_name=gs://experimental-pipeline-inversion-test/import/import-164-ringeriksbanen-5lines-nox)
    is complete
  - >-
    INFO: Informed scheduler that task  
    Processing_gs___experimenta_530bed4d8f   has status   PENDING
  - >-
    INFO: Informed scheduler that task   Import_gs___experimenta_0bc8fa99af  
    has status   DONE
  - 'INFO: Done scheduling tasks'
  - 'INFO: Running Worker with 1 processes'
  - 'DEBUG: Asking scheduler for work...'
  - 'DEBUG: Pending tasks: 1'
  - >-
    INFO: [pid 2054] Worker Worker(salt=1996346561, workers=1,
    host=7feb0e1c9131, username=root, pid=2054) running  
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
  - >-
    ERROR: [pid 2054] Worker Worker(salt=1996346561, workers=1,
    host=7feb0e1c9131, username=root, pid=2054) failed   
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
  - 'Traceback (most recent call last):'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/luigi/worker.py", line 210, in run'
  - '    new_deps = self._run_get_new_deps()'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/luigi/worker.py", line 138, in _run_get_new_deps'
  - '    task_gen = self.task.run()'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/beryl_pipeline/processing.py", line 80, in run'
  - '    fl_data.orig_xyz = data.orig_xyz_by_line[fline]'
  - 'KeyError: ''500101'''
  - 'DEBUG: 1 running tasks, waiting for next task to finish'
  - >-
    INFO: Informed scheduler that task  
    Processing_gs___experimenta_530bed4d8f   has status   FAILED
  - 'DEBUG: Asking scheduler for work...'
  - 'DEBUG: Done'
  - 'DEBUG: There are no more tasks to run at this time'
  - 'DEBUG: There are 1 pending tasks possibly being run by other workers'
  - 'DEBUG: There are 1 pending tasks unique to this worker'
  - 'DEBUG: There are 1 pending tasks last scheduled by this worker'
  - >-
    INFO: Worker Worker(salt=1996346561, workers=1, host=7feb0e1c9131,
    username=root, pid=2054) was stopped. Shutting down Keep-Alive thread
  - 'INFO: '
  - '===== Luigi Execution Summary ====='
  - ''
  - 'Scheduled 2 tasks of which:'
  - '* 1 complete ones were encountered:'
  - '    - 1 Import(import_name=gs://experimental-pipeline-inversion-test/import/import-164-ringeriksbanen-5lines-nox)'
  - '* 1 failed:'
  - '    - 1 Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)'
  - ''
  - This progress looks :( because there were failed tasks
  - ''
  - '===== Luigi Execution Summary ====='
  - ''
  - ''
  - ''
  - '2024-09-09 09:56:14,930: Traceback (most recent call last):'
  - '  File "/app/poltergust/__init__.py", line 203, in run'
  - '    for line in eval(command, scope):'
  - '  File "/usr/local/lib/python3.10/dist-packages/pieshell/utils/asyncutils.py", line 9, in it'
  - '    yield loop.run_until_complete(aitf.__anext__())'
  - '  File "/usr/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete'
  - '    return future.result()'
  - '  File "/usr/local/lib/python3.10/dist-packages/pieshell/iterio.py", line 212, in __anext__'
  - '    if self.at_eof: await self.at_eof()'
  - '  File "/usr/local/lib/python3.10/dist-packages/pieshell/pipeline/running.py", line 102, in wait'
  - '    raise PipelineFailed(self)'
  - >-
    pieshell.pipeline.running.PipelineFailed: Pipeline failed:
    luigi.Processing('--module=beryl_pipeline.processing',
    '--processing-name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2',
    '--scheduler-url=http://scheduler:8082', '--retcode-already-running=10',
    '--retcode-missing-data=20', '--retcode-not-run=25',
    '--retcode-task-failed=30', '--retcode-scheduling-error=35',
    '--retcode-unhandled-exception=40') as 2054 (exit_code=30) in
    [134:/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml]:
  - ''
  - >-
    luigi.Processing('--module=beryl_pipeline.processing',
    '--processing-name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2',
    '--scheduler-url=http://scheduler:8082', '--retcode-already-running=10',
    '--retcode-missing-data=20', '--retcode-not-run=25',
    '--retcode-task-failed=30', '--retcode-scheduling-error=35',
    '--retcode-unhandled-exception=40') as 2054 (exit_code=30) in
    [134:/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml]
  - 'stderr content:'
  - >-
    Loading S3 module without the python package boto3. Will crash at runtime if
    S3 functionality is used.
  - >-
    DEBUG: Checking if
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
    is complete
  - >-
    DEBUG: Checking if
    Import(import_name=gs://experimental-pipeline-inversion-test/import/import-164-ringeriksbanen-5lines-nox)
    is complete
  - >-
    INFO: Informed scheduler that task  
    Processing_gs___experimenta_530bed4d8f   has status   PENDING
  - >-
    INFO: Informed scheduler that task   Import_gs___experimenta_0bc8fa99af  
    has status   DONE
  - 'INFO: Done scheduling tasks'
  - 'INFO: Running Worker with 1 processes'
  - 'DEBUG: Asking scheduler for work...'
  - 'DEBUG: Pending tasks: 1'
  - >-
    INFO: [pid 2054] Worker Worker(salt=1996346561, workers=1,
    host=7feb0e1c9131, username=root, pid=2054) running  
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
  - >-
    ERROR: [pid 2054] Worker Worker(salt=1996346561, workers=1,
    host=7feb0e1c9131, username=root, pid=2054) failed   
    Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)
  - 'Traceback (most recent call last):'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/luigi/worker.py", line 210, in run'
  - '    new_deps = self._run_get_new_deps()'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/luigi/worker.py", line 138, in _run_get_new_deps'
  - '    task_gen = self.task.run()'
  - '  File "/tmp/environments/gs/experimental-pipeline-inversion-test/environment/introspection-58-0-0-3-5-20240907.yml/lib/python3.10/site-packages/beryl_pipeline/processing.py", line 80, in run'
  - '    fl_data.orig_xyz = data.orig_xyz_by_line[fline]'
  - 'KeyError: ''500101'''
  - 'DEBUG: 1 running tasks, waiting for next task to finish'
  - >-
    INFO: Informed scheduler that task  
    Processing_gs___experimenta_530bed4d8f   has status   FAILED
  - 'DEBUG: Asking scheduler for work...'
  - 'DEBUG: Done'
  - 'DEBUG: There are no more tasks to run at this time'
  - 'DEBUG: There are 1 pending tasks possibly being run by other workers'
  - 'DEBUG: There are 1 pending tasks unique to this worker'
  - 'DEBUG: There are 1 pending tasks last scheduled by this worker'
  - >-
    INFO: Worker Worker(salt=1996346561, workers=1, host=7feb0e1c9131,
    username=root, pid=2054) was stopped. Shutting down Keep-Alive thread
  - 'INFO: '
  - '===== Luigi Execution Summary ====='
  - ''
  - 'Scheduled 2 tasks of which:'
  - '* 1 complete ones were encountered:'
  - '    - 1 Import(import_name=gs://experimental-pipeline-inversion-test/import/import-164-ringeriksbanen-5lines-nox)'
  - '* 1 failed:'
  - '    - 1 Processing(processing_name=gs://experimental-pipeline-inversion-test/processing/processing-144-gp-manedits-v2)'
  - ''
  - This progress looks :( because there were failed tasks
  - ''

[burningsage]

I think this is a problem in the environment 0.0.3.5_20240907

[MetalnAlloys]

Did you try with a new environment?

[redhog]

This is an issue with flighline numbers / ints / floats / strings. I changed it recently. Make a new env.

[eddjharrison]

• [x] Test with new environemt, @MetalnAlloys please make one for Ben with latest of everything
• [ ] Ben @burningsage close once tested