Hi Brian, I can't help you with this problem, but I'm wondering whether you have to use this almost two years old version of Fuseki (2016-11-04) ? Probably an update won't solve your issues, but it might fix other bugs. Also, the performance might have been improved.
Cheers, Lorenz On 30.01.2018 08:05, Brian McBride wrote: > My appologies if you have seen this before: I'm having a little > trouble unsubscribing from an obsolete email address. > > I'm having a problem with fuseki backups. We do a nightly backup of a > Fuseki server and after about 3 weeks, the backups hang. Fuseki > continues serving queries normally. We are running Fuseki 2.4.1. > > If anyone has any knowledge about what might be going wrong here, I'd > appreciate hearing about it, otherwise I'd be happy to (help) > investigate as best I can. > > I have just caught the problem and poked around a little. > > The fuseki log for the day begins: > > [[ > > 2018-01-26 01:52:25.482 INFO Admin :: [1650] POST > http://localhost:3030/$/backup/ds > 2018-01-26 01:52:25.494 INFO Admin :: [1650] Backup > dataset /ds > > ]] > > and contains nothing else (well it didn't when I first looked at it). > > The log for the previous day begins: > > [[ > > 2018-01-25 01:52:46.083 INFO Admin :: [1551] POST > http://localhost:3030/$/backup/ds > 2018-01-25 01:52:46.083 INFO Admin :: [1551] Backup > dataset /ds > 2018-01-25 01:52:46.083 INFO Server :: Task : 21 : backup > 2018-01-25 01:52:46.107 INFO Server :: [Task 21] starts > : backup > 2018-01-25 01:52:46.107 INFO Backup :: [1551] >>>> > Start backup /ds -> /etc/fuseki/backups/ds_2018-01-25_01-52-46 > 2018-01-25 01:52:46.123 INFO Request :: 127.0.0.1 - - > [25/Jan/2018:01:52:46 +0000] "POST /$/backup/ds" 200 - "" "curl/7.47.0" > 2018-01-25 01:52:46.123 INFO Admin :: [1551] 200 OK > (39 ms) > 2018-01-25 01:52:46.782 INFO Backup :: [1551] <<<< > Finish backup /ds -> /etc/fuseki/backups/ds_2018-01-25_01-52-46 > 2018-01-25 01:52:46.782 INFO Server :: [Task 21] > finishes : backup > > ]] > > The command > > wget http://localhost:3030/tasks > > hangs. > > The daily backups are requested by the command > > [[ > > curl -X POST 'http://localhost:3030/$/backup/ds' > > ]] > > This also hangs. > > Restart fuseki and backups work again. > > > The problem is reproducable (in less than three weeks). I fired I > VirtualBox with the same configuration as our production servers and > no data. There is nothing I would consider unusual about the > configuration. The backup command is in the script > /usr/local/bin/fuseki-backup. > > > To reproduce use script test.sh: > > [[ > > #!/bin/bash > > for ((count=1; count<=25; count++)) > do > echo starting backup $count > fuseki-backup > sleep 5 > echo $count done > done > > ]] > > which outputs: > > [[ > > { > "taskId" : "1" , > "requestId" : 1 > } > 1 done > starting backup 2 > { > "taskId" : "2" , > "requestId" : 2 > } > 2 done > starting backup 3 > { > "taskId" : "3" , > "requestId" : 3 > } > 3 done > > ... > > 18 done > starting backup 19 > { > "taskId" : "19" , > "requestId" : 19 > } > 19 done > starting backup 20 > { > "taskId" : "20" , > "requestId" : 20 > } > 20 done > starting backup 21 > { > "taskId" : "21" , > "requestId" : 21 > } > 21 done > starting backup 22 > ]] > > and then hangs > > The fuseki log contains: > > [[ > > 2018-01-26 08:10:45.773 INFO Server :: Fuseki 2.4.1 > 2018-01-26 08:10:45.921 INFO Config :: > FUSEKI_HOME=/usr/share/fuseki > 2018-01-26 08:10:45.922 INFO Config :: > FUSEKI_BASE=/etc/fuseki > 2018-01-26 08:10:45.926 INFO Servlet :: Initializing > Shiro environment > 2018-01-26 08:10:45.926 INFO EnvironmentLoader :: Starting Shiro > environment initialization. > 2018-01-26 08:10:45.931 INFO Config :: Shiro file: > file:///etc/fuseki/shiro.ini > 2018-01-26 08:10:46.069 INFO EnvironmentLoader :: Shiro > environment initialized in 142 ms. > 2018-01-26 08:10:46.070 INFO Config :: Configuration > file: /etc/fuseki/config.ttl > 2018-01-26 08:10:46.572 WARN AssemblerHelp :: ja:loadClass: > Migration to Jena3: Converting com.hp.hpl.jena.tdb.TDB to > org.apache.jena.tdb.TDB > 2018-01-26 08:10:47.448 INFO Config :: Register: /ds > 2018-01-26 08:10:47.539 INFO Server :: Started > 2018/01/26 08:10:47 UTC on port 3030 > 2018-01-26 08:19:03.997 INFO Admin :: [1] GET > http://localhost:3030/$/backup > 2018-01-26 08:19:03.999 INFO Request :: 0:0:0:0:0:0:0:1 > - - [26/Jan/2018:08:19:03 +0000] "GET /$/backup" 200 - "" "Wget/1.17.1 > (linux-gnu)" > 2018-01-26 08:19:04.005 INFO Admin :: [1] 405 HTTP > method not allowed: GET (7 ms) > 2018-01-26 08:22:42.728 INFO Admin :: [2] POST > http://localhost:3030/$/backup/ds > 2018-01-26 08:22:42.729 INFO Admin :: [2] Backup > dataset /ds > 2018-01-26 08:22:42.731 INFO Server :: Task : 1 : backup > 2018-01-26 08:22:42.736 INFO Server :: [Task 1] starts > : backup > 2018-01-26 08:22:42.738 INFO Backup :: [2] >>>> Start > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-22-42 > 2018-01-26 08:22:42.740 INFO Request :: 0:0:0:0:0:0:0:1 > - - [26/Jan/2018:08:22:42 +0000] "POST /$/backup/ds" 200 - "" > "curl/7.47.0" > 2018-01-26 08:22:42.743 INFO Admin :: [2] 200 OK (11 ms) > 2018-01-26 08:22:42.753 INFO Backup :: [2] <<<< Finish > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-22-42 > 2018-01-26 08:22:42.753 INFO Server :: [Task 1] > finishes : backup > 2018-01-26 08:22:52.767 INFO Admin :: [3] POST > http://localhost:3030/$/backup/ds > 2018-01-26 08:22:52.767 INFO Admin :: [3] Backup > dataset /ds > 2018-01-26 08:22:52.767 INFO Server :: Task : 2 : backup > 2018-01-26 08:22:52.772 INFO Request :: 0:0:0:0:0:0:0:1 > - - [26/Jan/2018:08:22:52 +0000] "POST /$/backup/ds" 200 - "" > "curl/7.47.0" > 2018-01-26 08:22:52.772 INFO Admin :: [3] 200 OK (4 ms) > 2018-01-26 08:22:52.777 INFO Server :: [Task 2] starts > : backup > 2018-01-26 08:22:52.778 INFO Backup :: [3] >>>> Start > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-22-52 > 2018-01-26 08:22:52.779 INFO Backup :: [3] <<<< Finish > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-22-52 > 2018-01-26 08:22:52.780 INFO Server :: [Task 2] > finishes : backup > 2018-01-26 08:23:02.796 INFO Admin :: [4] POST > http://localhost:3030/$/backup/ds > 2018-01-26 08:23:02.796 INFO Admin :: [4] Backup > dataset /ds > 2018-01-26 08:23:02.797 INFO Server :: Task : 3 : backup > 2018-01-26 08:23:02.797 INFO Server :: [Task 3] starts > : backup > 2018-01-26 08:23:02.797 INFO Backup :: [4] >>>> Start > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-23-02 > 2018-01-26 08:23:02.798 INFO Backup :: [4] <<<< Finish > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-23-02 > 2018-01-26 08:23:02.798 INFO Server :: [Task 3] > finishes : backup > > > ... > > 2018-01-26 08:25:53.288 INFO Admin :: [21] POST > http://localhost:3030/$/backup/ds > 2018-01-26 08:25:53.289 INFO Admin :: [21] Backup > dataset /ds > 2018-01-26 08:25:53.289 INFO Server :: Task : 20 : backup > 2018-01-26 08:25:53.289 INFO Server :: [Task 20] starts > : backup > 2018-01-26 08:25:53.290 INFO Backup :: [21] >>>> Start > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-25-53 > 2018-01-26 08:25:53.291 INFO Backup :: [21] <<<< Finish > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-25-53 > 2018-01-26 08:25:53.291 INFO Server :: [Task 20] > finishes : backup > 2018-01-26 08:25:53.292 INFO Request :: 0:0:0:0:0:0:0:1 > - - [26/Jan/2018:08:25:53 +0000] "POST /$/backup/ds" 200 - "" > "curl/7.47.0" > 2018-01-26 08:25:53.292 INFO Admin :: [21] 200 OK (3 ms) > 2018-01-26 08:26:03.323 INFO Admin :: [22] POST > http://localhost:3030/$/backup/ds > 2018-01-26 08:26:03.325 INFO Admin :: [22] Backup > dataset /ds > 2018-01-26 08:26:03.325 INFO Server :: Task : 21 : backup > 2018-01-26 08:26:03.326 INFO Server :: [Task 21] starts > : backup > 2018-01-26 08:26:03.326 INFO Backup :: [22] >>>> Start > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-26-03 > 2018-01-26 08:26:03.327 INFO Backup :: [22] <<<< Finish > backup /ds -> /etc/fuseki/backups/ds_2018-01-26_08-26-03 > 2018-01-26 08:26:03.327 INFO Server :: [Task 21] > finishes : backup > 2018-01-26 08:26:03.330 INFO Request :: 0:0:0:0:0:0:0:1 > - - [26/Jan/2018:08:26:03 +0000] "POST /$/backup/ds" 200 - "" > "curl/7.47.0" > 2018-01-26 08:26:03.330 INFO Admin :: [22] 200 OK (5 ms) > 2018-01-26 08:26:13.344 INFO Admin :: [23] POST > http://localhost:3030/$/backup/ds > 2018-01-26 08:26:13.344 INFO Admin :: [23] Backup > dataset /ds > ]] > > and that is all. > > It may be coincidence, but top tells me that Fuseki has 21 threads > running suggesting maybe there is a limit on the number of task > threads and backups are not freeing the thread at the end of the backup. > > Brian > > >
