vingerha / gtfs2

Support GTFS in Home Assistant GUI-only
https://github.com/vingerha/gtfs2
MIT License
79 stars 7 forks source link

Bug: `homeassistant.exceptions.ConfigEntryNotReady: 'str' object has no attribute 'engine'` #42

Closed DistroByte closed 6 months ago

DistroByte commented 6 months ago

Describe the bug Unable to set up GTFS V2 using Transport for Ireland (tfi) data source.

Steps/data to reproduce the behavior, e.g.

Just trying to get the information into the app at all, using the "departures near a location" option when setting up a stop.

Auth is required for real time information via an API key, that may have some impact?

My datasource is named tfi-dublin-bus.

Release used HACS and the latest release as of today (2024-03-24)

Additional

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 318, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/gtfs2/coordinator.py", line 234, in _async_update_data
    self._data["local_stops_next_departures"] = await self.hass.async_add_executor_job(
                                                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/gtfs2/gtfs_helper.py", line 787, in get_local_stops_next_departures
    result = schedule.engine.connect().execute(
             ^^^^^^^^^^^^^^^
AttributeError: 'str' object has no attribute 'engine'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 350, in _async_setup_platform
    await asyncio.shield(awaitable)
  File "/config/custom_components/gtfs2/sensor.py", line 75, in async_setup_entry
    await coordinator.async_config_entry_first_refresh()
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 290, in async_config_entry_first_refresh
    raise ex
homeassistant.exceptions.ConfigEntryNotReady: 'str' object has no attribute 'engine'
$ ls -ahl /data/home-assistant/gtfs2/
total 78M
drwxrwxrwx 1 1024 users  142 Mar 24 19:19 .
drwxrwxrwx 1 1026 users  538 Mar 24 19:23 ..
-rwxrwxrwx 1 1024 users 188K Mar 24 19:19 tfi-dublin-bus.sqlite
-rwxrwxrwx 1 1024 users 1.7M Mar 24 19:19 tfi-dublin-bus_temp_out.zip
-rwxrwxrwx 1 1024 users  76M Mar 24 19:19 tfi-dublin-bus_temp.zip
$
DistroByte commented 6 months ago

When creating the datasource I get this error image

Using the "URL" option to create the source

vingerha commented 6 months ago

What I seem to see is that it got stuck at the initial clean of the zip (it removes unused objects to reduce extraction time) and my error-catching does not see this type of stuck/case, i.e. it should have not allowed you to continue to setup a route...which led to the larger set of errors... I will improve on it. But, I just tried to set this up with and all seems fine. The link above worked fine for me without any key and this is not (!) real-time data, the filename is misleading. Extracting took about 48 mins with me There should be two files left at the end. the sqlite and the zip

image

Can you please remove all three and start again?

DistroByte commented 6 months ago

Yeah I still haven't had any luck. I took the zip file from the table in the wiki and that works fine. Not really sure what the issue is tbh.

vingerha commented 6 months ago

Maybe the naming, can you try without the hyphen? EDIT (I am travelling, no access to test myself)

DistroByte commented 6 months ago

New source name dublin with new sensor test

$ ls -al
total 276180
drwxrwxrwx 1 1024 users       258 Mar 26 05:09 .
drwxrwxrwx 1 1026 users       544 Mar 25 05:44 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 24 20:02 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422397 Mar 24 19:59 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:09 dublin.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:09 dublin_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:09 dublin_temp.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
$

Same errors it would appear

image

vingerha commented 6 months ago

So is it still unpacking? Or just plain 'dead' ... "dublin-bus-gtfs" seemed to have worked indeed.. very curious

vingerha commented 6 months ago

Are you running HA docker or HAOS?

vingerha commented 6 months ago

I am just trying to find out how to try and replicate this

DistroByte commented 6 months ago

No, it's not doing anything. File size is staying the same. A minor note, when deleting thee dublin data source through the UI, dublin-bus-gtfs was also deleted.

I'm running the docker container

If it's any use, the /config directory is on an NFS mount, but as you can see there are no problems with other sources.

DistroByte commented 6 months ago
$ ls -al
total 190268
drwxrwxrwx 1 1024 users       194 Mar 26 05:13 .
drwxrwxrwx 1 1026 users       544 Mar 25 05:44 ..
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users 184799232 Mar 24 20:02 .nfs00000000001688e200000016
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:09 .nfs000000000016915500000017
$

Directory contents after removing the dublin data source.

vingerha commented 6 months ago

yeah...deleting is now deleting with *, I did not anticipate on multiple sources for the same area/city... will redo that too The .nfs are from the current process so these will go when you restart (I guess you know this already) Irish rail is working? i.e. only issues with the link all above this post?

DistroByte commented 6 months ago

Yep, irish-rail-gtfs works just fine, imported and parsing data correctly. As does the source you linked in the wiki GTFS_Dublin_Bus.zip

It honestly could be the original source being a zip of zips maybe? nevermind it's not, I just checked

vingerha commented 6 months ago

Can you try to run the integration in debug mode please... maybe something else will pop-up.

DistroByte commented 6 months ago

I'll see what I can do, give me a minute

vingerha commented 6 months ago

So we know the software works with you for other zip, we know the above link works with me..... brainfreeze

DistroByte commented 6 months ago

image image image

With debug logging enabled, I get the above logs into HA's log system.

image

DistroByte commented 6 months ago

home-assistant_gtfs2_2024-03-26T05-26-35.669Z.log

vingerha commented 6 months ago

Did you try to load a new source? The coordinator should imo not do anything

DistroByte commented 6 months ago

Yep, enabled debug log then ran through adding a new source (which does not throw any errors) then trying to do something with that source (in this case getting times of stops near a device/zone (my phone)), which is where the errors are thrown

vingerha commented 6 months ago

After you submitted the datasource, please donot try to add a stop...let it run. It may be that my check-on-etxracting is not working

vingerha commented 6 months ago

It seems that this is the case form the log... and I do admit that I haven't tested that in a long time

vingerha commented 6 months ago

Having thought it through, I believe this is the cause... the process is still trying to create a 'cleaned' new zip but somewhere it creates the sqlite...only after the new zip is there the sqlite-journal is being created and I check only on the latter... You seem to be too fast :) .... or: my check has gaps :)

DistroByte commented 6 months ago
distro@zeus:/data/home-assistant/gtfs2$ date
Tue 26 Mar 2024 05:32:42 GMT
distro@zeus:/data/home-assistant/gtfs2$ ls -al
total 457024
drwxrwxrwx 1 1024 users       432 Mar 26 05:32 .
drwxrwxrwx 1 1026 users       544 Mar 25 05:44 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users 184799232 Mar 24 20:02 .nfs00000000001688e200000016
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:09 .nfs000000000016915500000017
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:24 .nfs00000000001691a300000018
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:32 testing.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:32 testing_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:32 testing_temp.zip
distro@zeus:/data/home-assistant/gtfs2$ date
Tue 26 Mar 2024 05:33:08 GMT
distro@zeus:/data/home-assistant/gtfs2$ ls -al
total 457024
drwxrwxrwx 1 1024 users       432 Mar 26 05:32 .
drwxrwxrwx 1 1026 users       544 Mar 25 05:44 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users 184799232 Mar 24 20:02 .nfs00000000001688e200000016
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:09 .nfs000000000016915500000017
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:24 .nfs00000000001691a300000018
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:32 testing.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:32 testing_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:32 testing_temp.zip
distro@zeus:/data/home-assistant/gtfs2$ 

Okay after waiting 30 seconds, the file size has not changed

vingerha commented 6 months ago

You only added a new datasource? ...do use another name as this confuses me more :)

vingerha commented 6 months ago

FYI.... my re-zip is a bit overly complex but it worked stable... filename.zip is downloaded, then renamed to filename_temp.zip then this is cleaned to filename_temp_out.zip which is then again renamed to filename.zip

DistroByte commented 6 months ago

Sorry, I added the new datasource testing about 30 seconds before I ran the above commands. This is using the very first zip file I linked at the top of this issue.

Both the irish-rail-gtfs and dublin-bus-gtfs datasources work just fine. (both sources taken from the same list on the Transport for Ireland website)

vingerha commented 6 months ago

The re-zip prevented sqlite-journal creation during zip-cleaning. I use a external library to create the sqlite which is not really supported anylonger so have to come up with my own 'onventions' and I am not a real dev :)

DistroByte commented 6 months ago

I have not tried to get information from ~it~ the testing source (stop times or a route) because I can't see the journal file, and the sqlite file should be at least the same size as the other two sources.

vingerha commented 6 months ago

ok... well... not sure if it hangs now on other reasons (.nfs ?) ... but I now think I can replicate it...will try a fix end of the week

DistroByte commented 6 months ago

Okay, I don't think I can do much more troubleshooting for you now at this stage - perhaps I can make that small PR to change how files are deleted, but I don't have the time right now to solve this easily. I'm a Site Reliability Engineer, not a dev :D

I don't think the .nfs files affect it at all, seeing as there could be no pattern match there because it starts with a .nfs which I can almost guarantee does not occur in your codebase.

vingerha commented 6 months ago

My proposal is to restart (get rid of orphan processes), retry the datasource and wait before adding a stop. My extract took 50mins...

DistroByte commented 6 months ago

I don't think the nfs files are the problem. 4 datestamps here are:

distro@zeus:/data/home-assistant/gtfs2$ date
Tue 26 Mar 2024 05:43:40 GMT
distro@zeus:/data/home-assistant/gtfs2$ ls -al
total 198308
drwxrwxrwx 1 1024 users       164 Mar 26 05:40 .
drwxrwxrwx 1 1026 users       544 Mar 26 05:40 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
distro@zeus:/data/home-assistant/gtfs2$ date
Tue 26 Mar 2024 05:44:13 GMT
distro@zeus:/data/home-assistant/gtfs2$ ls -al
total 276180
drwxrwxrwx 1 1024 users       264 Mar 26 05:44 .
drwxrwxrwx 1 1026 users       544 Mar 26 05:40 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:44 testing.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:44 testing_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:44 testing_temp.zip
distro@zeus:/data/home-assistant/gtfs2$ date
Tue 26 Mar 2024 05:44:35 GMT
distro@zeus:/data/home-assistant/gtfs2$ ls -al
total 276180
drwxrwxrwx 1 1024 users       264 Mar 26 05:44 .
drwxrwxrwx 1 1026 users       544 Mar 26 05:40 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:44 testing.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:44 testing_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:44 testing_temp.zip
distro@zeus:/data/home-assistant/gtfs2$ date
Tue 26 Mar 2024 05:45:21 GMT
distro@zeus:/data/home-assistant/gtfs2$ ls -al
total 276180
drwxrwxrwx 1 1024 users       264 Mar 26 05:44 .
drwxrwxrwx 1 1026 users       544 Mar 26 05:40 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:44 testing.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:44 testing_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:44 testing_temp.zip
distro@zeus:/data/home-assistant/gtfs2$ 
DistroByte commented 6 months ago

The file size doesn't change at all, which leads me to believe the extract isn't occurring properly. I'll leave it overnight to see if anything changes, but I somehow doubt it.

Cheers for taking the time to help troubleshoot ❤️

vingerha commented 6 months ago

From temp to temp out this may take time, the process extracts file by file from one and compresses it to the _out.... for a large file this may take up to 20/30 mins (other datasource)..all depends on the machine/mem/cpuload/etc.

Koky05 commented 6 months ago

I have same issue with regional busses for Bratislava taken from IDSBK Open Data. It did not create journal at all. And even SQL database is smaller like ZIP file.

192512 Mar 26 11:59 20240318-AMS-gtfs.sqlite
532298 Mar 26 11:59 20240318-AMS-gtfs.zip

If I try older version 20240303-AMS-gtfs.zip it works correctly. Maybe I found problem in source file. After UnZIPing both the newer one has subfolder in it.

vingerha commented 6 months ago

If I try older version 20240303-AMS-gtfs.zip it works correctly. Maybe I found problem in source file. After UnZIPing both the newer one has subfolder in it.

Try turning on Debug Logging on the integration before you load the new data source. Without errors I cannot do much.

Koky05 commented 6 months ago

Like I wrote problem was on source of gtfs data side. They creates gtfs zip package with subfolder in it. After removing that subfolder and recreate zip file without it it work correctly and new source was created.

DistroByte commented 6 months ago
distro@zeus:~$ date
Thu 28 Mar 2024 00:20:57 GMT
distro@zeus:~$ ls -al /data/home-assistant/gtfs2/
total 276180
drwxrwxrwx 1 1024 users       264 Mar 26 07:21 .
drwxrwxrwx 1 1026 users       544 Mar 26 05:40 ..
-rwxrwxrwx 1 1024 users 184799232 Mar 26 05:20 dublin-bus-gtfs.sqlite
-rwxrwxrwx 1 1024 users   8422405 Mar 26 05:17 dublin-bus-gtfs.zip
-rwxrwxrwx 1 1024 users   9412608 Mar 24 19:59 irish-rail-gtfs.sqlite
-rwxrwxrwx 1 1024 users    427405 Mar 24 19:59 irish-rail-gtfs.zip
-rwxrwxrwx 1 1024 users    192512 Mar 26 05:48 testing.sqlite
-rwxrwxrwx 1 1024 users   1690283 Mar 26 05:48 testing_temp_out.zip
-rwxrwxrwx 1 1024 users  77854406 Mar 26 05:48 testing_temp.zip
distro@zeus:~$

For what it's worth, its been ~18 hours and nothing has changed.

vingerha commented 6 months ago

Release 0.4.2. now catches better if extracting still ongong and avoid crash of the sqlite. I cannot fix the issue why it is not extracting at all as I cannot reproduce that using the same url/source. Closing this topic