Experimental Physics and
Industrial Control System

Hi Mark, all,

I've setup a new epics installation today, and ran into the same autosave problem again, as the upstream master at https://github.com/epics-modules/autosave

still contains the bug. I suppose it would be good to fix this on upstream.

Cheers, Laurenz

I am quite sure this change between the latest tagged version (R5-10-2) and the master branch is the problem:

 

 

                } else if (pchannel->curr_elements <= 1) {

                        /* treat as scalar */

                        if (pchannel->enum_val >= 0) {

                                n = fprintf(out_fd, "%d\n",pchannel->enum_val);

                        } else {

-                               n = fprintf(out_fd, "%-s\n", pchannel->value);

+                               n = epicsStrPrintEscaped(out_fd, pchannel->value, strlen(pchannel->value));

+                               if (n > 0) {

+                                       n = fprintf(out_fd, "\n");

+                               }

                        }

                } else {

                        /* treat as array */

                        n = SR_write_array_data(out_fd, pchannel->name, (void *)pchannel->pArray, pchannel->curr_elements);

                }

                if (n <= 0) {

                        printf("save_restore:write_it: fprintf returned %d [%s].\n", n, datetime);

                        if (errno) myPrintErrno("write_it", __FILE__, __LINE__);

                        problem |= FPRINTF_FAILED;

 

Note that previously it used fprintf including a newline, so it would always return >0 as long as there was no error.

 

Now n is set by epicsStrPrintEscaped which might return 0, and only if it is >0 does it print a newline which will set n to 1.  This seems wrong for 2 reasons:

 

-          If epicsStrPrintEscaped returns 0 then there will be no newline, and the next PV in the output file will be on the same line as this one.

-          If epicsStrPrintEscaped returns 0 then it fails the n<=0 test, prints and error and never writes the file.

 

The commit with this error was done on November 14, 2019. 

https://github.com/epics-modules/autosave/commit/7fee24c91a37bc3a69420d6bb17732c839ba0cf8

 

However, it is not present in the R5-10-1 tag (April 17, 2020) or the R5-10-2 tag (October 4, 2020), because that PR was not merged until March 19, 2022. 

 

I just reverted to R5-10-2 and the autosave issue is fixed, my files are fine and the error messages no longer occur.

 

Mark

 

 

 

From: Mark Rivers
Sent: Wednesday, May 18, 2022 5:40 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

 

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.

-- 
Dr. Laurenz Rettig
Fritz Haber Institute of the Max Planck Society
Department of Physical Chemistry
Dynamics of Correlated Materials
Faradayweg 4-6
14195 Berlin, Germany

phone: +49-(0)30-8413 5225
email: rettig at fhi-berlin.mpg.de

Attachment: smime.p7s
Description: S/MIME Cryptographic Signature

References:

autosave problem Mark Rivers via Tech-talk

Re: autosave problem Johnson, Andrew N. via Tech-talk

RE: autosave problem Mark Rivers via Tech-talk

RE: autosave problem Mark Rivers via Tech-talk

RE: autosave problem Mark Rivers via Tech-talk

Navigate by Date:

Prev: Re: Write permission of a record Kasemir, Kay via Tech-talk

Next: RE: Write permission of a record Zhang, Tong via Tech-talk

Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  2019  2020  2021  <2022>  2023  2024 

Navigate by Thread:

Prev: RE: autosave problem Abdalla Ahmad via Tech-talk

Next: Bus errors accessing VME with base 7.0.6.1 and latest synApps modules Mark Rivers via Tech-talk

Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  2019  2020  2021  <2022>  2023  2024