RE: autosave problem

[Mark Rivers via Tech-talk <tech-talk at aps.anl.gov>]

This really seems like a problem in autosave. 

 

The save_restore:write_it function prints the same error message in 5 different places when fprintf() returns <=0.  I improved the code so it prints additional information so I know which error it is, and when it is writing data which PV it is writing. That additional information is highlighted in yellow below.

 

This is the output from 3 different VME IOCs running the new version of save_restore.c

 

corvette:CARS/iocBoot/ioc13ida>tail -10 ~/logs/13IDA.log

[Wed May 18 17:26:04 2022] save_restore:write_it: fprintf returned 0 when writing data for channel 13IDA:DMM1Dmm_calc.INPB [220518-172604].

[Wed May 18 17:26:04 2022] save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-172604]

[Wed May 18 17:26:04 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:04 2022] save_restore:write_save_file: Can't write save file. [220518-172604]

[Wed May 18 17:26:04 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:34 2022] save_restore:write_it: fprintf returned 0 when writing data for channel 13IDA:DMM1Dmm_calc.INPB [220518-172634].

[Wed May 18 17:26:34 2022] save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-172634]

[Wed May 18 17:26:34 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:34 2022] save_restore:write_save_file: Can't write save file. [220518-172634]

[Wed May 18 17:26:34 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

 

corvette:CARS/iocBoot/ioc13ida>tail -10 ~/logs/13BMA.log

[Wed May 18 17:25:53 2022] save_restore:write_it: fprintf returned 0 when writing data for channel 13BMA:DMM1Dmm_calc.INPB [220518-172553].

[Wed May 18 17:25:53 2022] save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-172553]

[Wed May 18 17:25:53 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:25:53 2022] save_restore:write_save_file: Can't write save file. [220518-172553]

[Wed May 18 17:25:54 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:23 2022] save_restore:write_it: fprintf returned 0 when writing data for channel 13BMA:DMM1Dmm_calc.INPB [220518-172623].

[Wed May 18 17:26:23 2022] save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-172623]

[Wed May 18 17:26:24 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:24 2022] save_restore:write_save_file: Can't write save file. [220518-172623]

[Wed May 18 17:26:24 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

 

corvette:CARS/iocBoot/ioc13ida>tail -10 ~/logs/13BMC.log

[Wed May 18 17:25:58 2022] save_restore:write_it: fprintf returned 0 when writing data for channel 13BMC:DMM1Dmm_calc.INPB [220518-172559].

[Wed May 18 17:25:59 2022] save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-172559]

[Wed May 18 17:25:59 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:25:59 2022] save_restore:write_save_file: Can't write save file. [220518-172559]

[Wed May 18 17:25:59 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:29 2022] save_restore:write_it: fprintf returned 0 when writing data for channel 13BMC:DMM1Dmm_calc.INPB [220518-172629].

[Wed May 18 17:26:29 2022] save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-172629]

[Wed May 18 17:26:29 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

[Wed May 18 17:26:29 2022] save_restore:write_save_file: Can't write save file. [220518-172629]

[Wed May 18 17:26:29 2022] *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

 

Note that they all fail when writing the INPB file of a calcout record.  This is dbpr on one of those records:

 

ioc13ida> dbpr "13IDA:DMM1Dmm_calc",1

A   : 9.9e+37       ADEL: 0             AMSG:               ASG :

B   : 0             BKPT: 00            C   : 0             CALC: A

CLCV: 0             D   : 0             DESC: Dmm Units     DISA: 0

DISP: 0             DISS: NO_ALARM      DISV: 1             DLYA: 0

DOPT: Use CALC      DTYP: Soft Channel  E   : 0             EGU :

EVNT:               F   : 0             FLNK: CONSTANT      G   : 0

H   : 0             HHSV: NO_ALARM      HIGH: 0             HIHI: 0

HOPR: 0             HSV : NO_ALARM      HYST: 0             I   : 0

INAV: Local PV      INBV: Constant      INCV: Constant      INDV: Constant

INEV: Constant      INFV: Constant      INGV: Constant      INHV: Constant

INIV: Constant      INJV: Constant      INKV: Constant      INLV: Constant

INPA: DB_LINK 13IDA:DMM1Dmm_raw.VAL NPP NMS                 INPB: CONSTANT

INPC: CONSTANT      INPD: CONSTANT      INPE: CONSTANT      INPF: CONSTANT

INPG: CONSTANT      INPH: CONSTANT      INPI: CONSTANT      INPJ: CONSTANT

INPK: CONSTANT      INPL: CONSTANT      J   : 0             K   : 0

L   : 0             LLSV: NO_ALARM      LOLO: 0             LOPR: 0

LOW : 0             LSV : NO_ALARM      MDEL: 0

NAME: 13IDA:DMM1Dmm_calc                NAMSG:              OCAL: 0

OCLV: 0             ODLY: 0             OEVT:               OOPT: Every Time

OUT : CONSTANT      OUTV: Constant      OVAL: 0             PACT: 0

PHAS: 0             PINI: NO            POVL: 0             PREC: 4

PRIO: LOW           PUTF: 0             PVAL: 0             RPRO: 0

SCAN: Passive       SDIS: CONSTANT      SEVR: INVALID       STAT: UDF

TPRO: 0             TSE : 0             TSEL: CONSTANT      UDF : 1

UDFS: INVALID       VAL : 0

value = 0 = 0x0

 

I suspect what is happening is that due to some recent commits the value being written is zero length, so fprintf is correctly returning 0, which is being misinterpreted as an error.

 

Mark

 

 

From: Mark Rivers
Sent: Wednesday, May 18, 2022 5:09 PM
To: Johnson, Andrew N. <anj at anl.gov>; mooney at aps.anl.gov
Cc: tech-talk at aps.anl.gov
Subject: RE: autosave problem

 

Hi Andrew,

 

Ø  Were there any changes to your file-server? I'm hoping that's not the system that Mrinal was upgrading to CentOS-8 last week.

 

The file server has not changed, it is Centos 7.

 

Ø  1058 bytes is less than a single UDP packet; can you try writing some other largeish file from VxWorks, just to make sure that isn't related. There is a "copy" command which might work for that, you give it an existing filename and a new one.

 

I just copied a file of about 16 kB  using the vxWorks shell.

ioc13ida> copy "motors.template","junk.txt"

value = 0 = 0x0

 

It worked fine, the output file junk.txt is the same as the input file.

 

corvette:CARS/iocBoot/ioc13ida>ls -l motors.template junk.txt

-rwxrwxrwx 1 epics domain users 16959 Jan  1  2020 junk.txt

-rwxrwxr-x 1 epics domain users 16959 Jan  1  2020 motors.template

 

I am adding some debugging to save_restore:write_it to figure out which fprintf failed and perhaps why.

 

Mark

 

 

From: Johnson, Andrew N. <anj at anl.gov>
Sent: Wednesday, May 18, 2022 4:59 PM
To: Mark Rivers <rivers at cars.uchicago.edu>; mooney at aps.anl.gov
Cc: tech-talk at aps.anl.gov
Subject: Re: autosave problem

 

Hi Mark,

Were there any changes to your file-server? I'm hoping that's not the system that Mrinal was upgrading to CentOS-8 last week. 1058 bytes is less than a single UDP packet; can you try writing some other largeish file from VxWorks, just to make sure that isn't related. There is a "copy" command which might work for that, you give it an existing filename and a new one.

- Andrew

On 5/18/22 4:52 PM, Mark Rivers wrote:

Folks,

 

I just upgraded my VME IOCs to base 7.0.6.1 and the master branch of autosave (some changes since 5-10-2).  I am getting these errors at the vxWorks prompt:

 

ioc13ida> save_restore:write_it: fprintf returned 0 [220518-163829].

save_restore:write_it: Giving up on this attempt to write 'auto_settings.sav'. [220518-163829]

*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

save_restore:write_save_file: Can't write save file. [220518-163829]

*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***

 

Recent files in the autosave/ directory are:

 

-rw-rw-rw- 1 epics domain users   2749 May 18 16:37 auto_positions.sav_220518-163750

-rw-rw-rw- 1 epics domain users   1058 May 18 16:37 auto_settings.sav_RBAD_220518-163750

-rw-rw-rw- 1 epics domain users   1058 May 18 16:37 auto_settings.sav_220518-163751

-rw-rw-rw- 1 epics domain users   1058 May 18 16:37 auto_settings.sav_RBAD_220518-163751

-rw-rw-r-- 1 epics domain users   2749 May 18 16:37 auto_positions.sav

-rw-rw-rw- 1 epics domain users   2749 May 18 16:37 auto_positions.savB

-rw-rw-r-- 1 epics domain users   1058 May 18 16:41 auto_settings.sav

 

Note that it is writing files.  However, the auto_settings.sav file is only 1058 bytes long, while it should be about 160 kB.  It seems like save_restore:write_it is writing some information to the file and then it gets an error.

 

This is the contents of the auto_settings.sav file:

 

corvette:iocBoot/ioc13ida/autosave>more auto_settings.sav

# autosave R5.3 Automatically generated - DO NOT MODIFY - 220518-164400

13IDA:ip2:SAUTOS 0

13IDA:ip2:DIS 0

13IDA:ip2:SSIZE 400

13IDA:ip2:ULCK 1

13IDA:ip2:SIZE.SCAN 6

13IDA:ip2:STAT.SCAN 6

13IDA:ip8:SAUTOS 0

13IDA:ip8:DIS 0

13IDA:ip8:SSIZE 400

13IDA:ip8:ULCK 0

13IDA:ip8:SIZE.SCAN 4

13IDA:ip8:STAT.SCAN 6

13IDA:ip9:SAUTOS 0

13IDA:ip9:DIS 0

13IDA:ip9:SSIZE 400

13IDA:ip9:ULCK 0

13IDA:ip9:SIZE.SCAN 4

13IDA:ip9:STAT.SCAN 6

13IDA:tsp1:TSP_FIL 0

13IDA:tsp1:TSP_AUTO_ADV 0

13IDA:tsp1:TSP_VALUE 50

13IDA:tsp1:TSP_UNITS 0

13IDA:tsp1:TSP_SECONDS 50

13IDA:tsp1:TSP_MINUTES 240

13IDA:tsp1:TSP_NCYCLES 900

13IDA:tsp1:TSP_MIN_PRESS 1e-10

13IDA:tsp1:TSP_STAT.SCAN 9

13IDA:DMM1dmm_chan.VAL 1

13IDA:DMM1ch_mode_sel.VAL 6

13IDA:DMM1init_string.VAL *rst;form:elem read

13IDA:DMM1onesh_cont.VAL 1

13IDA:DMM1single_multi.VAL 1

13IDA:DMM1scanner.SCAN 6

13IDA:DMM1Dmm_raw.DESC Dmm raw desc

13IDA:DMM1Dmm_calc.DESC Dmm Units

13IDA:DMM1Dmm_calc.PREC 4

13IDA:DMM1Dmm_calc.SCAN 0

13IDA:DMM1Dmm_calc.CALC A

13IDA:DMM1Dmm_calc.INPA 13IDA:DMM1Dmm_raw.VAL NPP NMS

13IDA:DMM1Dmm_calc.INPB

 

The disk that autosave it writing to has plenty of room.  What could be causing this error. 

 

It is happening on all 8 of my VME IOCs, it is not just with one of them.

 

Thanks,

Mark

 

 

 

-- 

Complexity is free, it's Simplicity that takes work.