t.list hangs on newly created temporal DB

[neteler]

t.list hangs when used on a newly created temporal DB which is still empty:

GRASS 7.1.svn (eu_laea):~ > t.list -h
D1/1: grass.script.core.start_command(): t.connect -c
D1/1: grass.script.core.start_command(): t.connect -pg
D1/1: grass.script.core.start_command(): g.gisenv -n
D1/1: Start messenger server
D1/1: Initiate the temporal database
D1/1: SQLDatabaseInterfaceConnection constructor
D1/1: Start C-interface server
----------------------------------------------
D1/1: SQLDatabaseInterfaceConnection constructor

... then it hangs. CTRL-C "helps":

^CProcess Process-2:
Process Process-1:
Traceback (most recent call last):
Traceback (most recent call last):
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 232, in _bootstrap
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 232, in _bootstrap
    self.run()
    self.run()
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 88, in run
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 88, in run
    self._target(*self._args, **self._kwargs)
    self._target(*self._args, **self._kwargs)
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/c_libraries_interface.py", line 644, in c_library_server
  File "/usr/local/grass-7.1.svn/etc/python/grass/pygrass/messages/__init__.py", line 73, in message_server
    conn.poll(None)
KeyboardInterrupt
    functions[data[0]](lock, conn, data)
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/c_libraries_interface.py", line 65, in available_mapsets
    if libgis.G__mapset_permissions(mapset) > 0:
KeyboardInterrupt
Traceback (most recent call last):
  File "/usr/local/grass-7.1.svn/scripts/t.list", line 157, in <module>
    main()
  File "/usr/local/grass-7.1.svn/scripts/t.list", line 111, in main
    stds_list = tgis.get_dataset_list(type,  ttype,  columns,  where,  order)
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/list_stds.py", line 73, in get_dataset_list
    mapsets = get_tgis_c_library_interface().available_mapsets()
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/c_libraries_interface.py", line 1088, in available_mapsets
    return self.client_conn.recv()
KeyboardInterrupt

Using strace:

strace t.list -h
...
D1/1: SQLDatabaseInterfaceConnection constructor
stat("/grassdata/eu_laea/PERMANENT/tgis/sqlite.db", {st_mode=S_IFREG|0644, st_size=159744, ...}) = 0
open("/grassdata/eu_laea/PERMANENT/tgis/sqlite.db", O_RDWR|O_CREAT, 0644) = 3
fcntl(3, F_GETFD)                       = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=159744, ...}) = 0
lseek(3, 0, SEEK_SET)                   = 0
read(3, "SQLite format 3\0\4\0\1\1\0@  \0\0\0X\0\0\0\0"..., 100) = 100
fcntl(3, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1073741824, len=1}) = 0
fcntl(3, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1073741826, len=510}) = 0
fcntl(3, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=1073741824, len=1}) = 0
access("/grassdata/eu_laea/PERMANENT/tgis/sqlite.db-journal", F_OK) = -1 ENOENT (No such file or directory)
fstat(3, {st_mode=S_IFREG|0644, st_size=159744, ...}) = 0
lseek(3, 0, SEEK_SET)                   = 0
read(3, "SQLite format 3\0\4\0\1\1\0@  \0\0\0X\0\0\0\0"..., 1024) = 1024
lseek(3, 5120, SEEK_SET)                = 5120
read(3, "\r\0\0\0\1\0\376\0\0\376\3\305\0z\0z\0\0\0\0\0\0G\4\6\27[5\1\0in"..., 1024) = 1024
lseek(3, 6144, SEEK_SET)                = 6144
read(3, "\r\0\0\0\3\1\201\0\1\201\1\270\3\267\0014\0014\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024) = 1024
...
read(3, "\r\0\0\0\6\0\300\0\0\300\1G\1\312\2/\2\320\3q\3u\0\0\0\0\0\0\0\0\0\0"..., 1024) = 1024
lseek(3, 149504, SEEK_SET)              = 149504
read(3, "\r\0\0\0\5\1_\0\1_\1\352\2G\2\340\3y\3\212\0\203\0\0\0\0\0\0\0\0\0\0"..., 1024) = 1024
lseek(3, 157696, SEEK_SET)              = 157696
read(3, "\r\0\0\0\5\1\301\0\2+\2\256\3$\3\222\1\301\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1024) = 1024
fcntl(3, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
wait4(11171, 0x7fff6df96024, WNOHANG, NULL) = 0
write(7, "\0\0\0\t\200\2]q\1K\10a.", 13) = 13
read(7,

It is polling for something unknown...

[huhabla]

I can not reproduce this behavior on my Ubuntu 12.04 64 Bit system:

GRASS 7.1.svn (nc_spm_08):~ > t.info -s
 +------------------- Temporal DBMI backend information ----------------------+
 | DBMI Python interface:...... sqlite3
 | Temporal database string:... /home/soeren/grassdata/nc_spm_08/PERMANENT/tgis/sqlite.db
 | SQL template path:.......... /home/soeren/src/grass7.0/grass_trunk/dist.x86_64-unknown-linux-gnu/etc/sql
 | tgis_db_version .......... 2
 | creation_time .......... 2014-06-29 20:23:20.576947
 | tgis_version .......... 2
 +----------------------------------------------------------------------------+
GRASS 7.1.svn (nc_spm_08):~ > rm /home/soeren/grassdata/nc_spm_08/PERMANENT/tgis/sqlite.db
GRASS 7.1.svn (nc_spm_08):~ > t.list -h
Creating temporal database:
/home/soeren/grassdata/nc_spm_08/PERMANENT/tgis/sqlite.db
----------------------------------------------
GRASS 7.1.svn (nc_spm_08):~ > t.list -h
----------------------------------------------
GRASS 7.1.svn (nc_spm_08):~ > 

Can you please give more information about the software environment?

[spareeth]

I am getting the same error with t.list, on a mapset with number of temporal datasets. Using compiled grass7.1 on Ubuntu 14.04 LTS , 64 bit machine. Here is the contents of my mapset folder.

ls -lh /grassdata/eu_laea/sp_garda_MODSST/
total 2.7M
drwxr-xr-x    2 sajid gis 336K Jun 18 19:26 cats
drwxr-xr-x    2 sajid gis 336K Jun 18 19:26 cell
drwxr-xr-x    2 sajid gis 336K Jun 18 19:26 cellhd
drwxr-xr-x 8466 sajid gis 336K Jun 18 19:26 cell_misc
drwxr-xr-x    2 sajid gis 168K Jun  3 14:21 colr
drwxr-xr-x    2 sajid gis 168K Jun 18 19:26 fcell
drwxr-xr-x    2 sajid gis 336K Jun 18 19:26 hist
-rw-r--r--    1 sajid gis   35 Jun  3 15:42 SEARCH_PATH
drwxr-xr-x    2 sajid gis   10 Jun  3 05:28 sqlite
drwxr-xr-x    2 sajid gis   30 Jun 16 14:48 tgis
-rw-r--r--    1 sajid gis  168 Jun 18 19:21 VAR
-rw-r--r--    1 sajid gis  325 Jun 16 12:20 WIND
[Raster MASK present]
GRASS 7.1.svn (eu_laea):/usr/local/src/grass7 > ls -lh /grassdata/eu_laea/sp_garda_MODSST/tgis/
total 9.9M
-rw-r--r-- 1 sajid gis 9.9M Jun 18 19:26 sqlite.db

Here is details of existing temporal datasets in the same mapset.

sqlite> select * from tgis_metadata;
tgis_db_version|2
creation_time|2014-06-16 14:48:41.645453
tgis_version|2
sqlite> select * from strds_metadata;
annual_count_MODSST@sp_garda_MODSST|raster_map_register_c985e0825e79458dafd50c8208950adc|11|169.0|0.0|219.0|0.0|1000.0|1000.0|1000.0|1000.0||count MODSST|obs count MODSST|# 2014-06-16 14:48:41 
t.create output="annual_count_MODSST" type="strds"
    semantictype="mean" temporaltype="absolute" title="count MODSST"
    description="obs count MODSST" --o
# 2014-06-16 14:49:57 
t.register -i input="annual_count_MODSST" type="rast"
    file="count_modsst.txt" start="2003-01-01" increment="1 years"

test@sp_garda_MODSST|raster_map_register_ee1246eeeae64bdbafdb47960ee305d5|||||||||||test|test|# 2014-06-17 13:32:00 
t.create output="test" type="strds"
    semantictype="mean" temporaltype="absolute" title="test"
    description="test" --o

Tdaily_modis_sst@sp_garda_MODSST|raster_map_register_1d62ff9fb6d749e3b860e74582b2f75c|4018|2238.0|1102.0|45727.0|42647.0|1000.0|1000.0|1000.0|1000.0||daily temperature from Mod sst raw|daily T from on modis sst raw|# 2014-06-18 18:55:25 
t.create output="Tdaily_modis_sst" type="strds"
    semantictype="mean" temporaltype="absolute"
    title="daily temperature from Mod sst raw"
    description="daily T from on modis sst raw" --o
# 2014-06-18 18:59:29 
t.register -i input="Tdaily_modis_sst" type="rast"
    file="filenames_mod_sst_raw_2003-2013.txt" start="2003-01-01"
    increment="1 days" --o

Tmean_seasonal_modis_sst@sp_garda_MODSST|raster_map_register_c26f830534a54fa4bed121e590b2cccf|44|14789.390244|1785.0|41666.0|34808.5|1000.0|1000.0|1000.0|1000.0|average|daily temperature from Mod sst raw|daily T from on modis sst raw|# 2014-06-18 18:59:31 
t.rast.aggregate input="Tdaily_modis_sst"
    output="Tmean_seasonal_modis_sst" base="Tmean_seasonal_modis_sst"
    granularity="3 months" method="average"
    where="start_time >=  2003-01-01  and start_time <  2014-01-01 " --o

Tmean_annual_modis_sst@sp_garda_MODSST|raster_map_register_1d916c3f94684bb89e68e8879c5a55da|11|26488.379085|17702.714286|29135.294521|20913.766667|1000.0|1000.0|1000.0|1000.0|average|daily temperature from Mod sst raw|daily T from on modis sst raw|# 2014-06-18 19:00:05 
t.rast.aggregate input="Tdaily_modis_sst"
    output="Tmean_annual_modis_sst" base="Tmean_annual_modis_sst"
    granularity="1 years" method="average"
    where="start_time >=  2003-01-01  and start_time <  2014-01-01 " --o

Tmean_deg_summer_modis_sst@sp_garda_MODSST|raster_map_register_cb672539b4184d8895354d5ab410dc44|11|24.321675|18.935825|27.882229|22.964133|1000.0|1000.0|1000.0|1000.0||daily temperature from Mod sst raw|daily T from on modis sst raw|# 2014-06-18 19:00:20 
t.rast.extract input="Tmean_seasonal_modis_sst"
    where="strftime( %m , start_time)= 07 "
    expression="(Tmean_seasonal_modis_sst * 0.000717184972) - 2"
    output="Tmean_deg_summer_modis_sst" base="Tmean_deg_summer_modis_sst"
    nprocs="4" --o

Tmean_deg_winter_modis_sst@sp_garda_MODSST|raster_map_register_38a34bcf8ef649c5aac0c01d8176acbc|11|8.606728|7.445736|10.870829|9.222654|1000.0|1000.0|1000.0|1000.0||daily temperature from Mod sst raw|daily T from on modis sst raw|# 2014-06-18 19:00:22 
t.rast.extract input="Tmean_seasonal_modis_sst"
    where="strftime( %m , start_time)= 01 "
    expression="(Tmean_seasonal_modis_sst * 0.000717184972) - 2"
    output="Tmean_deg_winter_modis_sst" base="Tmean_deg_winter_modis_sst"
    nprocs="4" --o

Tdaily_modis_sst_hants@sp_garda_MODSST|raster_map_register_a25db159e0ef40268a21c4b6189afea8|4018|13552.926495|-7030.313965|55117.719349|37973.938564|1000.0|1000.0|1000.0|1000.0||daily temperature from Mod sst hants|daily T from on modis sst hants|# 2014-06-18 19:21:07 
t.create output="Tdaily_modis_sst_hants" type="strds"
    semantictype="mean" temporaltype="absolute"
    title="daily temperature from Mod sst hants"
    description="daily T from on modis sst hants" --o
# 2014-06-18 19:25:22 
t.register -i input="Tdaily_modis_sst_hants"
    type="rast" file="filenames_mod_sst_hants_2003-2013.txt"
    start="2003-01-01" increment="1 days" --o

Tmean_seasonal_modis_sst_hants@sp_garda_MODSST|raster_map_register_486e2c47f714412caf1fa6a31bff5823|44|14919.961618|5379.516413|45305.797911|36157.819222|1000.0|1000.0|1000.0|1000.0|average|daily temperature from Mod sst hants|daily T from on modis sst hants|# 2014-06-18 19:25:24 
t.rast.aggregate input="Tdaily_modis_sst_hants"
    output="Tmean_seasonal_modis_sst_hants"
    base="Tmean_seasonal_modis_sst_hants" granularity="3 months"
    method="average"
    where="start_time >=  2003-01-01  and start_time <  2014-01-01 " --o

Tmean_annual_modis_sst_hants@sp_garda_MODSST|raster_map_register_8e844b411ed54f8e80537c58508ce2b7|11|25236.554709|19846.125419|28924.264045|24954.117264|1000.0|1000.0|1000.0|1000.0|average|daily temperature from Mod sst hants|daily T from on modis sst hants|# 2014-06-18 19:26:15 
t.rast.aggregate input="Tdaily_modis_sst_hants"
    output="Tmean_annual_modis_sst_hants"
    base="Tmean_annual_modis_sst_hants" granularity="1 years"
    method="average"
    where="start_time >=  2003-01-01  and start_time <  2014-01-01 " --o

Tmean_deg_summer_modis_sst_hants@sp_garda_MODSST|raster_map_register_98da1449fb394111b61d931da7ce52eb|11|24.284032|21.462871|27.860518|23.931845|1000.0|1000.0|1000.0|1000.0||daily temperature from Mod sst hants|daily T from on modis sst hants|# 2014-06-18 19:26:33 
t.rast.extract input="Tmean_seasonal_modis_sst_hants"
    where="strftime( %m , start_time)= 07 "
    expression="(Tmean_seasonal_modis_sst_hants * 0.000717184972) - 2"
    output="Tmean_deg_summer_modis_sst_hants"
    base="Tmean_deg_summer_modis_sst_hants" nprocs="4" --o

Tmean_deg_winter_modis_sst_hants@sp_garda_MODSST|raster_map_register_9ae7825d4f574e59bd5035c36a0b3b29|11|8.700372|7.571384|10.890343|9.823787|1000.0|1000.0|1000.0|1000.0||daily temperature from Mod sst hants|daily T from on modis sst hants|# 2014-06-18 19:26:35 
t.rast.extract input="Tmean_seasonal_modis_sst_hants"
    where="strftime( %m , start_time)= 01 "
    expression="(Tmean_seasonal_modis_sst_hants * 0.000717184972) - 2"
    output="Tmean_deg_winter_modis_sst_hants"
    base="Tmean_deg_winter_modis_sst_hants" nprocs="4" --o

t.list -c hangs and forced to ctrl-c, giving the following error trace.

Process Process-2:
Traceback (most recent call last):
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
Traceback (most recent call last):
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/scripts/t.list", line 157, in <module>
    main()
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/scripts/t.list", line 111, in main
    stds_list = tgis.get_dataset_list(type,  ttype,  columns,  where,  order)
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/etc/python/grass/temporal/list_stds.py", line 73, in get_dataset_list
    self.run()
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/etc/python/grass/temporal/c_libraries_interface.py", line 644, in c_library_server
    mapsets = get_tgis_c_library_interface().available_mapsets()
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/etc/python/grass/temporal/c_libraries_interface.py", line 1088, in available_mapsets
    return self.client_conn.recv()
    functions[data[0]](lock, conn, data)
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/etc/python/grass/temporal/c_libraries_interface.py", line 65, in available_mapsets
    if libgis.G__mapset_permissions(mapset) > 0:
KeyboardInterrupt
KeyboardInterrupt
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    self.run()
  File "/usr/lib/python2.7/multiprocessing/process.py", line 114, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/src/grass7/dist.x86_64-unknown-linux-gnu/etc/python/grass/pygrass/messages/__init__.py", line 73, in message_server
    conn.poll(None)
KeyboardInterrupt

[spareeth]

Update: Looks like the issue is with the nfs system of the cluster where the mapset is stored. When the same mapset is copied to local machine, t.list works without any problem.

Let me know of any more information required to debug this issue.

Sajid

[neteler]

Reporting again with hanging t.create: We run current GRASS 7.1.svn in the office and mount /grassdata via NFS3 from our cluster frontend machine.

With strace we got an idea where the problem is. Note that the user is not operating in the mapset "lexem_matteo" cited below nor is it in the mapset search path but it simply exists in the same location which we share among our group:

GRASS 7.1.svn (eu_laea): >
strace t.create output=Tdaily_modis_hants type=strds semantictype=mean
temporaltype=absolute title="daily temperature from Mod lst hants"
description="daily T from hants on modis lst"
...
getuid()                                = 10014
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
getuid()                                = 10014
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
getuid()                                = 10014
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
getuid()                                = 10014
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
[...]
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
getuid()                                = 10014
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
getuid()                                = 10014
stat("/grassdata/eu_laea/lexem_matteo", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
[...]
^CTraceback (most recent call last):
  File "/usr/local/grass-7.1.svn/scripts/t.create", line 84, in <module>
    main()
  File "/usr/local/grass-7.1.svn/scripts/t.create", line 77, in main
    tgis.init()
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/core.py",
line 593, in init
Process Process-1:
Process Process-2:
Traceback (most recent call last):
Traceback (most recent call last):
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 232, in
_bootstrap
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 232, in
_bootstrap
    self.run()
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 88, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/grass-7.1.svn/etc/python/grass/pygrass/messages/__init__.py",
line 65, in message_server
    self.run()
  File "/usr/lib64/python2.6/multiprocessing/process.py", line 88, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/c_libraries_interface.py",
line 769, in c_library_server
    conn.poll(None)
KeyboardInterrupt
    dbif = SQLDatabaseInterfaceConnection()
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/core.py",
line 839, in __init__
    self.tgis_mapsets = get_available_temporal_mapsets()
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/core.py",
line 439, in get_available_temporal_mapsets
    mapsets = c_library_interface.available_mapsets()
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/c_libraries_interface.py",
line 1220, in available_mapsets
    return self.client_conn.recv()
KeyboardInterrupt
    functions[data[0]](lock, conn, data)
  File "/usr/local/grass-7.1.svn/etc/python/grass/temporal/c_libraries_interface.py",
line 159, in _available_mapsets
    if libgis.G_mapset_permissions(mapset) > 0:
KeyboardInterrupt

The ID of the actual user is 10014.

PROBLEM: The issue happens in line 142 lib/python/temporal/c_libraries_interface.py

function def _available_mapsets(lock, conn, data):

where a while loop is used. The issue is apparently caused by the fact that in our current cluster setup, after reinstallation, the NFS daemon doesn't properly map the user ID's to the local workstation in the office where not all users are existing. While we have to fix this, it should not lead to an endless loop:

Apparently libgis.G_mapset_permissions() does not behave properly for this NFS case. It should be able to leave the while loop rather than getting stuck there.

# example for one of our NFS mounted directories as seen on the office
workstation:
ls -la /grassdata/eu_laea/lexem_matteo
total 312
drwxr-xr-x  13 10012 gis   4096 Jan 17 16:09 .
drwxrwxr-x 125  1338 gis  16384 Feb  3 18:35 ..
-rw-------   1 10012 gis 122050 Jan  1 18:26 .bash_history
-rw-r--r--   1 10012 gis   1949 Jan 17 16:09 .bashrc
drwxr-xr-x   2 10012 gis  20480 Dec 27 14:22 cats
drwxr-xr-x   2 10012 gis  20480 Dec 27 14:22 cell
drwxr-xr-x   2 10012 gis  20480 Dec 27 14:22 cellhd
drwxr-xr-x  19 10012 gis  20480 Dec 27 14:22 cell_misc
...

--> user IDs not transmitted, our problem, but libgis.G_mapset_permissions() doesn't deal with it properly (or def_available_mapsets()).

[huhabla]

I tried to fix the while loop in c_libraries_interface.py (r64470) that hopefully contribute to solve the problem. Unfortunately i have no NFS setup to test it properly.

[neteler]

Replying to huhabla:

I tried to fix the while loop in c_libraries_interface.py (r64470) that hopefully contribute to solve the problem. Unfortunately i have no NFS setup to test it properly.

Thanks! Initial tests with our NFS show that r64470 solves the endless loop issue.

I'd suggest to backport it if no other side-effects occur.

[spareeth]

Hi

The solution is not yet backported into GRASS 7.0.1

Can we have it done?

Thank you

Sajid

[neteler]

Replying to spareeth:

The solution is not yet backported into GRASS 7.0.1

Done in r65103 through backport of r64470. Closing ticket.