search

oracc / nisaba

GNU General Public License v3.0
3 stars 0 forks source link

Validation and lemmatisation of remote ATF files occasionally fails #144

Open giordano opened 1 year ago

giordano commented 1 year ago

Trying to run lemmatisation or validation of ATF files on a remote server occasionally, but not always, fails with error

[nisaba] error: Unexpected message from server: /home/oracc/tmp/sop/Nq2aO2/status not found (-1)

No problems when running the same commands on a local file with the same content.

This is the part of the code I'm less familiar with, but looking at the source I'm struggling to see what we do differently between remote and local files (and remote files are actually local for the remote instance of VS Code we're running).

Log of a successful run of validation on a remote file:

2023-01-16T22:08:49.415Z [nisaba] debug: Extracting project code for na-archival.atf
2023-01-16T22:08:49.417Z [nisaba] debug: Project code found: "cams/gkab"
2023-01-16T22:08:49.428Z [nisaba] debug: Full message boundary: W3d51xbu
2023-01-16T22:08:49.428Z [nisaba] debug: Full message envelope: Content-Type: application/xop+xml; charset="utf-8"; type="application/soap+xml"
Content-Transfer-Encoding: binary
MIME-Version: 1.0
Content-ID: <SOAP-ENV:Envelope>

<?xml version="1.0" encoding="UTF-8"?>
        <SOAP-ENV:Envelope
            xmlns:SOAP-ENV="http://www.w3.org/2003/05/soap-envelope"
            xmlns:SOAP-ENC="http://www.w3.org/2003/05/soap-encoding"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xmlns:xsd="http://www.w3.org/2001/XMLSchema"
            xmlns:xop="http://www.w3.org/2004/08/xop/include"
            xmlns:xmime5="http://www.w3.org/2005/05/xmlmime"
            xmlns:osc-data="http://oracc.org/wsdl/ows.xsd"
            xmlns:osc-meth="http://oracc.org/wsdl/ows.wsdl">
            <SOAP-ENV:Body>
                <osc-meth:Request>
                    <osc-data:keys>
                        <osc-data:key>atf</osc-data:key>
                        <osc-data:key>cams/gkab</osc-data:key>
                        <osc-data:key>00atf/na-archival.atf</osc-data:key>
                    </osc-data:keys>
                    <osc-data:data>
                        <osc-data:item xmime5:contentType="*/*">
                            <xop:Include href="cid:request_zip"/>
                        </osc-data:item>
                    </osc-data:data>
                </osc-meth:Request>
            </SOAP-ENV:Body>
        </SOAP-ENV:Envelope>
2023-01-16T22:08:49.455Z [nisaba] debug: Got response code jSEHl5
2023-01-16T22:08:49.467Z [nisaba] debug: Server working on request jSEHl5
                                      (attempt 1).
2023-01-16T22:08:49.675Z [nisaba] debug: Server working on request jSEHl5
                                      (attempt 2).
2023-01-16T22:08:49.883Z [nisaba] debug: Server working on request jSEHl5
                                      (attempt 3).
2023-01-16T22:08:50.091Z [nisaba] debug: Result ready after 4 attempts.
2023-01-16T22:08:50.091Z [nisaba] debug: Request jSEHl5 is done.
2023-01-16T22:08:50.098Z [nisaba] debug: Log file name: request.log
2023-01-16T22:08:50.099Z [nisaba] debug: Log contents: oracc-exec.sh[2]: jSEHl5 /tmp/dataGGhvm2 atf cams/gkab 00atf/na-archival.atf
oracc-exec.plx[v001]: jSEHl5 /tmp/dataGGhvm2 atf cams/gkab 00atf/na-archival.atf
oracc_exec: pwd=/home/oracc/tmp/sop/jSEHl5
xsystem /home/oracc/sbin/osc-create.sh jSEHl5 cams/gkab
tempdir=/home/oracc/tmp/sop/jSEHl5; projdir=/home/oracc/cams/gkab
create_project cams/gkab
chmod: cannot access 'cams/gkab': No such file or directory
/home/oracc/sbin/osc-create.sh: line 8: cd: cams/gkab: No such file or directory
/home/oracc/tmp/sop/jSEHl5
ls: cannot access 'cams/gkab/01bld': No such file or directory
cams/gkab/01bld is not a link ... autofixing ...
cbd after removing link dirs
ls: cannot access '02www/cbd': No such file or directory
xsystem unzip /tmp/dataGGhvm2
Archive:  /tmp/dataGGhvm2
  inflating: 00atf/na-archival.atf   
xsystem /home/oracc/bin/ox -l /home/oracc/tmp/sop/jSEHl5/oracc.log -cvmD 00atf/na-archival.atf
xsystem zip -j /home/oracc/tmp/sop/jSEHl5/response.zip /home/oracc/tmp/sop/jSEHl5/request.log /home/oracc/tmp/sop/jSEHl5/oracc.log
  adding: request.log
2023-01-16T22:08:50.099Z [nisaba] debug: Log file name: oracc.log
2023-01-16T22:08:50.099Z [nisaba] debug: Log contents: 
2023-01-16T22:08:50.100Z [nisaba] info: ATF validation returned no errors.

Log of the same command, now unsuccessful, run soon after:

2023-01-16T22:08:52.506Z [nisaba] debug: Extracting project code for na-archival.atf
2023-01-16T22:08:52.506Z [nisaba] debug: Project code found: "cams/gkab"
2023-01-16T22:08:52.510Z [nisaba] debug: Full message boundary: OoujkUA7
2023-01-16T22:08:52.510Z [nisaba] debug: Full message envelope: Content-Type: application/xop+xml; charset="utf-8"; type="application/soap+xml"
Content-Transfer-Encoding: binary
MIME-Version: 1.0
Content-ID: <SOAP-ENV:Envelope>

<?xml version="1.0" encoding="UTF-8"?>
        <SOAP-ENV:Envelope
            xmlns:SOAP-ENV="http://www.w3.org/2003/05/soap-envelope"
            xmlns:SOAP-ENC="http://www.w3.org/2003/05/soap-encoding"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xmlns:xsd="http://www.w3.org/2001/XMLSchema"
            xmlns:xop="http://www.w3.org/2004/08/xop/include"
            xmlns:xmime5="http://www.w3.org/2005/05/xmlmime"
            xmlns:osc-data="http://oracc.org/wsdl/ows.xsd"
            xmlns:osc-meth="http://oracc.org/wsdl/ows.wsdl">
            <SOAP-ENV:Body>
                <osc-meth:Request>
                    <osc-data:keys>
                        <osc-data:key>atf</osc-data:key>
                        <osc-data:key>cams/gkab</osc-data:key>
                        <osc-data:key>00atf/na-archival.atf</osc-data:key>
                    </osc-data:keys>
                    <osc-data:data>
                        <osc-data:item xmime5:contentType="*/*">
                            <xop:Include href="cid:request_zip"/>
                        </osc-data:item>
                    </osc-data:data>
                </osc-meth:Request>
            </SOAP-ENV:Body>
        </SOAP-ENV:Envelope>
2023-01-16T22:08:52.517Z [nisaba] debug: Got response code Nq2aO2
2023-01-16T22:08:52.525Z [nisaba] error: Unexpected message from server: /home/oracc/tmp/sop/Nq2aO2/status not found (-1)
giordano commented 1 year ago

Another example, with more logging enabled for good measure. Successful run:

2023-01-17T00:27:11.727Z [nisaba] debug: Extracting project code for arabic_with_lem.atf
2023-01-17T00:27:11.730Z [nisaba] debug: Project code found: "cams/gkab"
2023-01-17T00:27:11.730Z [nisaba] debug: fileName: arabic_with_lem.atf
2023-01-17T00:27:11.730Z [nisaba] debug: fileProject: cams/gkab
2023-01-17T00:27:11.730Z [nisaba] debug: fileContent: &X001001 = JCS 48, 089
#project: cams/gkab
#atf: lang akk-x-stdbab
#atf: use unicode
#atf: use math
@tablet
@obverse

1.  [MU] 1.03-KAM {iti}AB GE₆ U₄ 2-KAM
#lem: šanat[year]N; n; Ṭebetu[1]MN; mūša[at night]AV; ūm[day]N; n

@translation parallel ar project
@obverse

1. في شتة ٦٣ في شهر تبت، يوم ٢

2023-01-17T00:27:11.737Z [nisaba] debug: Full message boundary: Rr9lsXJq
2023-01-17T00:27:11.737Z [nisaba] debug: Full message envelope: Content-Type: application/xop+xml; charset="utf-8"; type="application/soap+xml"
Content-Transfer-Encoding: binary
MIME-Version: 1.0
Content-ID: <SOAP-ENV:Envelope>

<?xml version="1.0" encoding="UTF-8"?>
        <SOAP-ENV:Envelope
            xmlns:SOAP-ENV="http://www.w3.org/2003/05/soap-envelope"
            xmlns:SOAP-ENC="http://www.w3.org/2003/05/soap-encoding"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xmlns:xsd="http://www.w3.org/2001/XMLSchema"
            xmlns:xop="http://www.w3.org/2004/08/xop/include"
            xmlns:xmime5="http://www.w3.org/2005/05/xmlmime"
            xmlns:osc-data="http://oracc.org/wsdl/ows.xsd"
            xmlns:osc-meth="http://oracc.org/wsdl/ows.wsdl">
            <SOAP-ENV:Body>
                <osc-meth:Request>
                    <osc-data:keys>
                        <osc-data:key>atf</osc-data:key>
                        <osc-data:key>cams/gkab</osc-data:key>
                        <osc-data:key>00atf/arabic_with_lem.atf</osc-data:key>
                    </osc-data:keys>
                    <osc-data:data>
                        <osc-data:item xmime5:contentType="*/*">
                            <xop:Include href="cid:request_zip"/>
                        </osc-data:item>
                    </osc-data:data>
                </osc-meth:Request>
            </SOAP-ENV:Body>
        </SOAP-ENV:Envelope>
2023-01-17T00:27:11.758Z [nisaba] debug: Got response code bsbk72
2023-01-17T00:27:11.768Z [nisaba] debug: Server working on request bsbk72
                                      (attempt 1).
2023-01-17T00:27:11.975Z [nisaba] debug: Server working on request bsbk72
                                      (attempt 2).
2023-01-17T00:27:12.181Z [nisaba] debug: Server working on request bsbk72
                                      (attempt 3).
2023-01-17T00:27:12.389Z [nisaba] debug: Result ready after 4 attempts.
2023-01-17T00:27:12.389Z [nisaba] debug: Request bsbk72 is done.
2023-01-17T00:27:12.396Z [nisaba] debug: Log file name: request.log
2023-01-17T00:27:12.396Z [nisaba] debug: Log contents: oracc-exec.sh[2]: bsbk72 /tmp/data4YbVk3 atf cams/gkab 00atf/arabic_with_lem.atf
oracc-exec.plx[v001]: bsbk72 /tmp/data4YbVk3 atf cams/gkab 00atf/arabic_with_lem.atf
oracc_exec: pwd=/home/oracc/tmp/sop/bsbk72
xsystem /home/oracc/sbin/osc-create.sh bsbk72 cams/gkab
tempdir=/home/oracc/tmp/sop/bsbk72; projdir=/home/oracc/cams/gkab
create_project cams/gkab
chmod: cannot access 'cams/gkab': No such file or directory
/home/oracc/sbin/osc-create.sh: line 8: cd: cams/gkab: No such file or directory
/home/oracc/tmp/sop/bsbk72
ls: cannot access 'cams/gkab/01bld': No such file or directory
cams/gkab/01bld is not a link ... autofixing ...
cbd after removing link dirs
ls: cannot access '02www/cbd': No such file or directory
xsystem unzip /tmp/data4YbVk3
Archive:  /tmp/data4YbVk3
  inflating: 00atf/arabic_with_lem.atf  
xsystem /home/oracc/bin/ox -l /home/oracc/tmp/sop/bsbk72/oracc.log -cvmD 00atf/arabic_with_lem.atf
xsystem zip -j /home/oracc/tmp/sop/bsbk72/response.zip /home/oracc/tmp/sop/bsbk72/request.log /home/oracc/tmp/sop/bsbk72/oracc.log
  adding: request.log
2023-01-17T00:27:12.397Z [nisaba] debug: Log file name: oracc.log
2023-01-17T00:27:12.397Z [nisaba] debug: Log contents: 
2023-01-17T00:27:12.398Z [nisaba] info: ATF validation returned no errors.

Failing run:

2023-01-17T00:28:05.356Z [nisaba] debug: Extracting project code for arabic_with_lem.atf
2023-01-17T00:28:05.356Z [nisaba] debug: Project code found: "cams/gkab"
2023-01-17T00:28:05.356Z [nisaba] debug: fileName: arabic_with_lem.atf
2023-01-17T00:28:05.357Z [nisaba] debug: fileProject: cams/gkab
2023-01-17T00:28:05.357Z [nisaba] debug: fileContent: &X001001 = JCS 48, 089
#project: cams/gkab
#atf: lang akk-x-stdbab
#atf: use unicode
#atf: use math
@tablet
@obverse

1.  [MU] 1.03-KAM {iti}AB GE₆ U₄ 2-KAM
#lem: šanat[year]N; n; Ṭebetu[1]MN; mūša[at night]AV; ūm[day]N; n

@translation parallel ar project
@obverse

1. في شتة ٦٣ في شهر تبت، يوم ٢

2023-01-17T00:28:05.358Z [nisaba] debug: Full message boundary: YZ8c6IVG
2023-01-17T00:28:05.358Z [nisaba] debug: Full message envelope: Content-Type: application/xop+xml; charset="utf-8"; type="application/soap+xml"
Content-Transfer-Encoding: binary
MIME-Version: 1.0
Content-ID: <SOAP-ENV:Envelope>

<?xml version="1.0" encoding="UTF-8"?>
        <SOAP-ENV:Envelope
            xmlns:SOAP-ENV="http://www.w3.org/2003/05/soap-envelope"
            xmlns:SOAP-ENC="http://www.w3.org/2003/05/soap-encoding"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
            xmlns:xsd="http://www.w3.org/2001/XMLSchema"
            xmlns:xop="http://www.w3.org/2004/08/xop/include"
            xmlns:xmime5="http://www.w3.org/2005/05/xmlmime"
            xmlns:osc-data="http://oracc.org/wsdl/ows.xsd"
            xmlns:osc-meth="http://oracc.org/wsdl/ows.wsdl">
            <SOAP-ENV:Body>
                <osc-meth:Request>
                    <osc-data:keys>
                        <osc-data:key>atf</osc-data:key>
                        <osc-data:key>cams/gkab</osc-data:key>
                        <osc-data:key>00atf/arabic_with_lem.atf</osc-data:key>
                    </osc-data:keys>
                    <osc-data:data>
                        <osc-data:item xmime5:contentType="*/*">
                            <xop:Include href="cid:request_zip"/>
                        </osc-data:item>
                    </osc-data:data>
                </osc-meth:Request>
            </SOAP-ENV:Body>
        </SOAP-ENV:Envelope>
2023-01-17T00:28:05.367Z [nisaba] debug: Got response code nR7iK1
2023-01-17T00:28:05.375Z [nisaba] error: Unexpected message from server: /home/oracc/tmp/sop/nR7iK1/status not found (-1)

Note that fileName, fileProject and fileContent are the three arguments of https://github.com/oracc/nisaba/blob/0050341b980259f9c26ac99615656ff5dffc7cfe/src/server/messages.ts#L8-L12 They are identical in both cases (and identical to what I'd get for a local file with the same name and content), I don't see why we would get different return messages.

ageorgou commented 1 year ago

In case it's not clear, the error message seems to indicate that the corresponding temporary files have not been created on the server. This could be due to not enough storage (unlikely if it only happens occasionally) or because we send the follow-up request too quickly. The latter might explain why it's not a problem with "local" (i.e. not-on-server) files, if the latency from the network allows enough time for the server to start processing the request.

Perhaps adding a little delay before starting to send the status requests (to see if the result is ready) would smooth this, similar to the fix in #112?