Understanding VfS Error Log

[40th]

I'm having issues with the new V-Ray fSU (v1.48.66).
But the biggest one is when the VFB doesn't show up, i.e the rendering process doesn't start (as discribed here: Link)

I'm trying to find the cause for this in the "Error Log", but I don't know how to find the error indicator among all the text in the log.
My question is what should I look for in the error log in order to understand the cause of not being able to render?

I've uploaded the Error Log of the problematic scene: http://www.mediafire.com/?ojdyixwabkk

[dkendig]

Re: Understanding VfS Error Log

The error log is a text document. Just copy and paste the contents rather than waste time uploading/downloading it. I would like everyone to be able to self-diagnose the issues, but we also understand that at the moment, there is no documentation about this stuff, so that will be kind of hard for you guys to do. So just post your error log, and let's see what's wrong. If you don't mind 40th, I'm posting your error log, and breaking it down a bit as we go through it:

About to make our qapp
after make qapp
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:47: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
self.message = messages[errorCode] % msgargs
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:47: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
self.message = messages[errorCode] % msgargs
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:48: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
Exception.__init__(self, self.message, args)
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:48: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
Exception.__init__(self, self.message, args)
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\Catalog.py:583: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
e.message),
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\Catalog.py:583: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
e.message),
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\Catalog.py:584: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
FtWarning)
FtWarning: Catalog resource (file:///C:/Python26/Share/4Suite/default.cat) disabled: Error retrieving resource 'file:///C:/Python26/Share/4Suite/default.cat (C:\\Python26\\Share\\4Suite\\default.cat)': [Errno 2] No such file or directory: 'C:\\Python26\\Share\\4Suite\\default.cat'
C:\ProgramData\ASGVIS\VfS\\VRayPlugins.xml
Made it after UIManager.initialize

This stuff is just a bunch of warnings. It can be ignored. Everyone should have the same stuff at the bottom of the error log.

Failed to construct the class...(<type 'exceptions.ValueError'>, ValueError(u'Invalid literal for float: /Tiles/Reflection/transparency_texture/TexFresnel/Texture1',), <traceback object at 0x1A0FCF08>)
Traceback (most recent call last):
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayplugin.py", line 651, in handle_float
return VRayType("float", self._grab_child_text_node_data( node ) )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 1612, in __new__
return cls(*args)
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 261, in __init__
self.set( value )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 264, in set
self.value = _helperToFloat( val )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 13, in _helperToFloat
res = toFloat(val.strip())
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\visutils.py", line 218, in toFloat
raise ValueError( error_msg )
ValueError: Invalid literal for float: /Tiles/Reflection/transparency_texture/TexFresnel/Texture1

So the error here is the part where it says "ValueError: Invalid literal for float: /Tiles/Reflection/transparency_texture/TexFresnel/Texture1". What does it mean? Well it's telling us that it was expecting a float value (a number that has a decimal point like 5.3), but instead we got a literal value of some sort. So... what does that mean? Well basically... somewhere along the lines, something that was expecting a number... didn't get a number, it got some other garbage. What did it get? I don't know, but we could probably figure it out if we had the scene in front of us to play around with. Basically we would just keep pressing buttons, trying to follow whatever the users tells us they did to produce the problem, until we saw that error appear in the error log. So... maybe this happened when you tried to set a texture for a material.

Let's see here... it says "/Tiles/Reflection/transparency_texture/TexFresnel/Texture1" So there's a material in your scene called "Tiles". It has a Reflection layer. The transparency_texture currently is set to be a TexFresnel texture. One of the values of the TexFresnel has another map set of some sort, and that's the guy that has an invalid value of some sort. Tada! There's a problem with that material for some reason. So take a look at the material called "Tiles" and see if you can see anything wrong with it.

C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\InputSource.py:346: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
FtWarning, 2)
FtWarning: Creation of InputSource without a URI

This is just another warning, not relevant.

there is already a sun
update_sun_xml_in_scene was just called with the following argList:[u'SunLight']

This is just some stuff that prints out when we're doing some checks to see if we should put the Physical Sun in the scene or not.

Entering renderArchive
About to start readArchive - C:\ProgramData/ASGVIS/VfS/current_skp.xml

Okay, so now it looks like you pressed the render button. When you render, an xml document is generated, which represents the ENTIRE scene. All geometry, materials, render options, etc. It's all in there. The file is called "C:\ProgramData/ASGVIS/VfS/current_skp.xml". Feel free to look at it whenever you have an issue, to see if you can see anything weird. I'm going to warn you though, it's a large text document and there isn't anything useful you can do with that document other than look at it. If you're familiar with programming or XML, maybe this will make sense to you a little, if you're not familiar with that stuff though... I don't think I'd recommend even opening that file to look at it.

Failed to construct the class...(<type 'exceptions.ValueError'>, ValueError(u'Invalid literal for float: /Tiles/Reflection/transparency_texture/TexFresnel/Texture1',), <traceback object at 0x23A00E68>)
Traceback (most recent call last):
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayplugin.py", line 651, in handle_float
return VRayType("float", self._grab_child_text_node_data( node ) )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 1612, in __new__
return cls(*args)
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 261, in __init__
self.set( value )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 264, in set
self.value = _helperToFloat( val )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vraytypes.py", line 13, in _helperToFloat
res = toFloat(val.strip())
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\visutils.py", line 218, in toFloat
raise ValueError( error_msg )
ValueError: Invalid literal for float: /Tiles/Reflection/transparency_texture/TexFresnel/Texture1

There's that texture again...

24.071000 seconds is how long it took to read in our scene file

This is how long it took for us to read in that xml scene file: C:\ProgramData/ASGVIS/VfS/current_skp.xml

Traceback (most recent call last):
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 230, in initFromArchive
self.addAssetsToRenderer( self )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 92, in addAssetsToRenderer
self.__findReferencedPlugins( asset, refList )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 126, in __findReferencedPlugins
self.__handleReferencedPlugin( param.value, referencedList )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 117, in __handleReferencedPlugin
referencedAsset = self.assets_lookup[ paramUrl ]
KeyError: u'/Chrome'

Okay, so this one says that when we trying to find some assets that were referenced in another plugin, we were unable to find them. What does that mean? It means that let's say... a sphere, has a material applied to it. The Geometry asset would make reference to that material, specifically that the material is applied to the front or back side of a face of that geometry. So in this particular instance, there is something that is referencing a material called "/Chrome" I know that this is the URL of a material, and not a texture, because you can't name anything in our plugin, aside from materials, and there's nothing in our plugin called "Chrome". So more than likely this is a material in your scene. Unfortunately we were unable to find that material while iterating through the assets in the scene.

So where is the material? SketchUp's probably hiding it somewhere. It's probably a material that was applied to a component that was imported, or some other input method other than creating a material directly from the SketchUp material editor.

So why does that matter? Why should it matter how a material is brought in to the scene? It shouldn't matter, but unfortunately since SketchUp decided to not give us a heads up when a material is created by importing a component or however it happened, we don't know that we need to handle that material, so the material isn't dealt with, and the scene doesn't work. It's just the way it works. Our old product didn't deal with this issue properly either, but at least now there's a work around. You can run our new Debug tools.

Specifically you can run the Force Sync for All Materials tool. This will iterate through all of the materials in the SketchUp material editor, and the V-Ray material editor. It will find any materials that are missing from the editors, and create materials where needed so both editors reflect the same materials. If you were to run that tool on this scene, you would probably notice an extra material that magically appears in the V-Ray material editor, called Chrome. You might not see that same material show up in the SketchUp material editor, because the material may already exist somewhere in the scene, hidden from view (I hate that SketchUp does this... oh I hate it so much).

Okay, moving on...

Traceback (most recent call last):
File "C:\ProgramData\ASGVIS\VfS\PyProcMsg.py", line 46, in procPyCallback
callback( argList )
File "C:\ProgramData\ASGVIS\VfS\pyCallbacks.py", line 179, in start_render
renderer.renderArchive( argList[0] )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 260, in renderArchive
self.initFromArchive( filename )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 230, in initFromArchive
self.addAssetsToRenderer( self )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 92, in addAssetsToRenderer
self.__findReferencedPlugins( asset, refList )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 126, in __findReferencedPlugins
self.__handleReferencedPlugin( param.value, referencedList )
File "C:\ProgramData\ASGVIS\Python26\Lib\site-packages\ASGVIS\vrayrender.py", line 117, in __handleReferencedPlugin
referencedAsset = self.assets_lookup[ paramUrl ]
KeyError: u'/Chrome'

Again, the material named "Chrome" is missing from the XML scene file that was written out after clicking the render button. So the geometry that was using that material was written out, and it knew that it had a material named "Chrome" with a URL of "/Chrome" applied to at least one of it's faces, but there is no /Chrome in the scene, so an error occurs.
_________________________________________________

I know this breakdown doesn't answer all questions about the error log, but I do hope that I've been able to shed some light on the issue, and have managed to help some of you. Please keep the error logs coming, so we can continue to diagnose issues, and discover as many bugs as we can. The more bugs we know about, the more effective the next patch will be!

[40th]

Re: Understanding VfS Error Log

That's exactly the explanation I was hoping for. Thank you Devin.

So here's what I've done before I've seen your explanation (since I had to move along with the work):

I saw the "chrome" word in the log associated with an error, so I deleted it and made a new one. Your description of the problem fits the case cause I copy-pasted objects with this material applied to the current scene. I also tried the sync tool before deleting the material, but it didn't help.

Regarding the "Tile" material, I've also seen it in the log: "Invalid literal for float: /Tiles/Reflection/transparency_texture/TexFresnel/Texture1".
I had a specular map applied in the perpendicular slot under frensel reflection type. So I figured that the map caused the problem.
It's a bit off topic, but in the previous VfS (1.05.30) that was exactly the slot where I always set the specular map. Now it's seems to cause errors.

Thanks again Devin for taking the time to write this explanation. I appreciate it and believe that VfS and ASGvis has a lot of potential and just needs time to grow. I want to say that you guys doing a great job and with a little patience VfS will become more powerful and more reliable.

[dkendig]

Re: Understanding VfS Error Log

You said you tried running the sync tool and it did not fix the issue. I'm curious though, did you try to render, get an error, and then run the sync tool? Or did you try running the sync tool, render, and then get an error? The reason I ask, is that sometimes when an error occurs, it can stop a process halfway. This could lead to unexpected results.

If I encounter a situation where I need to run debug tools, here's what I do:

(I usually recommend that you save often)

-An error occurs
-If possible, save the file as a different file name as a backup. Keep in mind that this scene may have some sort of problem with it, but it's still good to save any progress you can.
-Close SketchUp
-Open the scene again in a fresh instance of SketchUp.
-Try to reproduce the error.
-If the error occurs again, then it's probably happening due to something that just happened, and it's not part of another issue.
-Close the scene without saving (there shouldn't have been any changes made anyway).
-Look at the error log, see if there's anything that looks like a missing material or some other type of error
-Save a backup of the error log (the error log gets deleted every time you open SketchUp, so save a backup)
-Open the scene again
-Now run any debug tools that may apply to the situation.

[40th]

Re: Understanding VfS Error Log

Ok I'll keep that in mind next time.

What happened in my case was: render> error> Sync tool> render> error

[dkendig]

Re: Understanding VfS Error Log

The problem with render -> error -> Sync tool -> render, is that the first error could have caused something to stop halfway though a process. Then you try to use the sync tool, and it doesn't work because the scene is broken and if an error occurred on the Ruby side of the equation, then our plugin sort of gets ignored by SketchUp. That's why if you get an error like this, it's best to just save your progress in a new file, close SketchUp, open the scene again, then debug and then render.

[40th]

Re: Understanding VfS Error Log

That's why if you get an error like this, it's best to just save your progress in a new file, close SketchUp, open the scene again, then debug and then render.

Good tip to know about.

[a3rosmith]

Re: Understanding VfS Error Log

i cant found a vfs error log in mac there are not in tmp folder

[dkendig]

Re: Understanding VfS Error Log

/tmp is a hidden folder by default (thanks apple). So if you open Finder, and click on Go->Go to folder, and then type in /tmp in the prompt that appears, you should see the folder pop up in finder.

[a3rosmith]

Re: Understanding VfS Error Log

ohhh ok i found it !!! thanks

[omegaslasher]

Re: Understanding VfS Error Log

So I recognize some of this stuff but then the error I get at the end that I don't see in this forum. Any ideas?

About to make our qapp
after make qapp
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:47: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
self.message = messages[errorCode] % msgargs
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:47: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
self.message = messages[errorCode] % msgargs
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:48: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
Exception.__init__(self, self.message, args)
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Lib\__init__.py:48: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
Exception.__init__(self, self.message, args)
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\Catalog.py:583: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
e.message),
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\Catalog.py:583: DeprecationWarning: BaseException.message has been deprecated as of Python 2.6
e.message),
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\Catalog.py:584: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
FtWarning)
FtWarning: Catalog resource (file:///C:/Python26/Share/4Suite/default.cat) disabled: Error retrieving resource 'file:///C:/Python26/Share/4Suite/default.cat (C:\\Python26\\Share\\4Suite\\default.cat)': [Errno 2] No such file or directory: 'C:\\Python26\\Share\\4Suite\\default.cat'
C:\ProgramData\ASGVIS\VfS\\VRayPlugins.xml
Made it after UIManager.initialize
C:\ProgramData\ASGVIS\Python26\Lib\site-packages\Ft\Xml\InputSource.py:346: DeprecationWarning: functions overriding warnings.showwarning() must support the 'line' argument
FtWarning, 2)
FtWarning: Creation of InputSource without a URI

[dkendig]

Re: Understanding VfS Error Log

actually, everything above where it says "FtWarning: Creation of InputSource without a URI" is just useless warning messages. So there are no errors in that error log.

[omegaslasher]

Re: Understanding VfS Error Log

after looking in to your discussion of the limitations of the 32-bit program, I think I've found that is consistently the issue with all of my "freezes". Anytime I approach 1.5 GB in the task manager it shuts down. This happens when I use the method described for large renderings as well. So right now I'm just trying to figure out how to get high quality renderings that are a decent size.

I guess until there is a 64-bit version of sketchup, that VfSU is not the the future of my work...which is a shame because I love alot of things it does. But when there's a finite ceiling to what it can do, I guess it just is what it is.

Thanks for the help though!

[dkendig]

Re: Understanding VfS Error Log

Sure thing, yeah sometimes you just need to find the right tool for the job. Then again, there might be something wrong with the scene. Have you emailed our support department? We don't really use the forums to support users, it's only there for users to talk to other users. There might be something wrong with that scene that could be fixed. Also, did you try the latest beta version? I haven't seen any postings by you in the beta forum.

[thomthom]

Re: Understanding VfS Error Log

after looking in to your discussion of the limitations of the 32-bit program, I think I've found that is consistently the issue with all of my "freezes". Anytime I approach 1.5 GB in the task manager it shuts down. This happens when I use the method described for large renderings as well. So right now I'm just trying to figure out how to get high quality renderings that are a decent size.

I guess until there is a 64-bit version of sketchup, that VfSU is not the the future of my work...which is a shame because I love alot of things it does. But when there's a finite ceiling to what it can do, I guess it just is what it is.

Thanks for the help though!

You have the option of rendering to file, that preserves memory better and allows you to render larger models in higher resolutions.